logging.c 31.3 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"
E
Eric Blake 已提交
45
#include "virfile.h"
46
#include "virtime.h"
47

48 49
#define VIR_FROM_THIS VIR_FROM_NONE

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

54 55
static int virLogSize = 64 * 1024;
static char *virLogBuffer = NULL;
D
Daniel Veillard 已提交
56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78
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 {
79
    bool logVersion;
D
Daniel Veillard 已提交
80 81 82 83
    void *data;
    virLogOutputFunc f;
    virLogCloseFunc c;
    int priority;
84 85
    virLogDestination dest;
    const char *name;
D
Daniel Veillard 已提交
86 87 88 89 90 91 92 93 94 95
};
typedef struct _virLogOutput virLogOutput;
typedef virLogOutput *virLogOutputPtr;

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

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

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

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

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

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

static const char *virLogPriorityString(virLogPriority lvl) {
    switch (lvl) {
133 134 135 136 137 138 139 140
    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 已提交
141
    }
142
    return "unknown";
D
Daniel Veillard 已提交
143 144 145 146 147 148 149 150 151 152 153 154
}

static int virLogInitialized = 0;

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

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

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

D
Daniel Veillard 已提交
163 164
    virLogInitialized = 1;
    virLogLock();
165
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
166 167 168 169 170 171
        /*
         * 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;
172
        if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
173 174 175 176 177 178
            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 已提交
179 180 181
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
182
    virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
183
    virLogUnlock();
184
    if (pbm)
185
        VIR_WARN("%s", pbm);
186
    return 0;
D
Daniel Veillard 已提交
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 215 216
/**
 * 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;

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

    virLogSize = size * 1024;
224
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242
        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 已提交
243 244 245 246 247 248 249 250 251
/**
 * 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)
252
        return virLogStartup();
D
Daniel Veillard 已提交
253 254 255 256 257 258 259

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

/*
 * Store a string in the ring buffer
 */
287 288
static void virLogStr(const char *str)
{
D
Daniel Veillard 已提交
289
    int tmp;
290
    int len;
D
Daniel Veillard 已提交
291

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

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

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

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

330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351
    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 已提交
352
 */
353 354
void
virLogEmergencyDumpAll(int signum) {
355
    int len;
C
Christophe Fergeau 已提交
356
    int oldLogStart, oldLogLen;
D
Daniel Veillard 已提交
357

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

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

    /*
     * 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 已提交
422
        } else {
423
            len = virLogSize - oldLogStart;
424
            virLogBuffer[virLogSize] = 0;
425 426 427
            virLogDumpAllFD(&virLogBuffer[oldLogStart], len);
            oldLogLen -= len;
            oldLogStart = 0;
D
Daniel Veillard 已提交
428 429
        }
    }
430
    virLogDumpAllFD("\n\n     ====== end of log =====\n\n", -1);
D
Daniel Veillard 已提交
431
}
432

D
Daniel Veillard 已提交
433 434 435 436 437 438 439 440 441 442 443
/**
 * 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) {
444
    if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) {
445
        VIR_WARN("Ignoring invalid log level setting.");
446
        return -1;
447
    }
D
Daniel Veillard 已提交
448 449 450
    if (!virLogInitialized)
        virLogStartup();
    virLogDefaultPriority = priority;
451
    return 0;
D
Daniel Veillard 已提交
452 453 454 455 456 457 458 459 460 461 462 463 464 465 466 467
}

/**
 * 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;
468
    return i;
D
Daniel Veillard 已提交
469 470 471 472 473 474 475 476 477 478 479 480 481 482 483 484
}

/**
 * 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,
485 486
                       unsigned int flags)
{
D
Daniel Veillard 已提交
487 488 489
    int i;
    char *mdup = NULL;

490 491
    virCheckFlags(0, -1);

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

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

    mdup = strdup(match);
505
    if (mdup == NULL) {
D
Daniel Veillard 已提交
506 507 508 509 510 511 512 513 514 515 516 517 518 519
        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();
520
    return i;
D
Daniel Veillard 已提交
521 522 523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544
}

/**
 * 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();
545
    return ret;
D
Daniel Veillard 已提交
546 547 548 549 550 551 552 553 554 555 556 557 558 559 560
}

/**
 * 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);
561
        VIR_FREE(virLogOutputs[i].name);
D
Daniel Veillard 已提交
562 563 564 565
    }
    VIR_FREE(virLogOutputs);
    i = virLogNbOutputs;
    virLogNbOutputs = 0;
566
    return i;
D
Daniel Veillard 已提交
567 568 569 570 571
}

/**
 * virLogDefineOutput:
 * @f: the function to call to output a message
572
 * @c: the function to call to close the output (or NULL)
D
Daniel Veillard 已提交
573 574
 * @data: extra data passed as first arg to the function
 * @priority: minimal priority for this filter, use 0 for none
575 576
 * @dest: where to send output of this priority
 * @name: optional name data associated with an output
D
Daniel Veillard 已提交
577 578 579 580 581 582 583 584
 * @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,
585
                       int priority, int dest, const char *name,
586 587
                       unsigned int flags)
{
D
Daniel Veillard 已提交
588
    int ret = -1;
589
    char *ndup = NULL;
D
Daniel Veillard 已提交
590

591 592
    virCheckFlags(0, -1);

D
Daniel Veillard 已提交
593
    if (f == NULL)
594
        return -1;
D
Daniel Veillard 已提交
595

596 597
    if (dest == VIR_LOG_TO_SYSLOG || dest == VIR_LOG_TO_FILE) {
        if (name == NULL)
598
            return -1;
599 600
        ndup = strdup(name);
        if (ndup == NULL)
601
            return -1;
602 603
    }

D
Daniel Veillard 已提交
604 605
    virLogLock();
    if (VIR_REALLOC_N(virLogOutputs, virLogNbOutputs + 1)) {
606
        VIR_FREE(ndup);
D
Daniel Veillard 已提交
607 608 609
        goto cleanup;
    }
    ret = virLogNbOutputs++;
610
    virLogOutputs[ret].logVersion = true;
D
Daniel Veillard 已提交
611 612 613 614
    virLogOutputs[ret].f = f;
    virLogOutputs[ret].c = c;
    virLogOutputs[ret].data = data;
    virLogOutputs[ret].priority = priority;
615 616
    virLogOutputs[ret].dest = dest;
    virLogOutputs[ret].name = ndup;
D
Daniel Veillard 已提交
617 618
cleanup:
    virLogUnlock();
619
    return ret;
D
Daniel Veillard 已提交
620 621
}

622

623 624 625 626 627 628 629 630
static int
virLogFormatString(char **msg,
                   const char *funcname,
                   long long linenr,
                   int priority,
                   const char *str)
{
    int ret;
631 632 633 634 635 636 637 638

    /*
     * 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.
     */
639
    if ((funcname != NULL)) {
640 641 642
        ret = virAsprintf(msg, "%d: %s : %s:%lld : %s\n",
                          virThreadSelfID(), virLogPriorityString(priority),
                          funcname, linenr, str);
643
    } else {
644 645 646
        ret = virAsprintf(msg, "%d: %s : %s\n",
                          virThreadSelfID(), virLogPriorityString(priority),
                          str);
647 648 649 650 651
    }
    return ret;
}

static int
652
virLogVersionString(char **msg)
653 654 655 656 657 658 659 660 661 662 663 664 665 666
{
#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

667
    return virLogFormatString(msg, NULL, 0, VIR_LOG_INFO, LOG_VERSION_STRING);
668 669
}

D
Daniel Veillard 已提交
670 671 672 673
/**
 * virLogMessage:
 * @category: where is that message coming from
 * @priority: the priority level
674 675
 * @funcname: the function emitting the (debug) message
 * @linenr: line where the message was emitted
D
Daniel Veillard 已提交
676 677 678 679 680 681 682
 * @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
 */
683
void virLogMessage(const char *category, int priority, const char *funcname,
684 685
                   long long linenr, unsigned int flags, const char *fmt, ...)
{
686
    static bool logVersionStderr = true;
D
Daniel Veillard 已提交
687
    char *str = NULL;
688
    char *msg = NULL;
689
    char timestamp[VIR_TIME_STRING_BUFLEN];
690
    int fprio, i, ret;
691
    int saved_errno = errno;
692
    int emit = 1;
E
Eric Blake 已提交
693
    va_list ap;
D
Daniel Veillard 已提交
694 695 696 697 698

    if (!virLogInitialized)
        virLogStartup();

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

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

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

D
Daniel Veillard 已提交
715 716 717
    /*
     * serialize the error message, add level and timestamp
     */
E
Eric Blake 已提交
718 719 720
    va_start(ap, fmt);
    if (virVasprintf(&str, fmt, ap) < 0) {
        va_end(ap);
721
        goto cleanup;
E
Eric Blake 已提交
722 723
    }
    va_end(ap);
D
Daniel Veillard 已提交
724

725
    ret = virLogFormatString(&msg, funcname, linenr, priority, str);
726
    VIR_FREE(str);
727 728
    if (ret < 0)
        goto cleanup;
D
Daniel Veillard 已提交
729

730 731
    if (virTimeStringNowRaw(timestamp) < 0)
        timestamp[0] = '\0';
732

D
Daniel Veillard 已提交
733
    /*
734 735
     * 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 已提交
736 737 738 739 740
     * 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.
     */
741 742 743 744
    virLogLock();
    virLogStr(timestamp);
    virLogStr(msg);
    virLogUnlock();
745 746 747
    if (emit == 0)
        goto cleanup;

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

781
cleanup:
782
    VIR_FREE(msg);
783
    errno = saved_errno;
D
Daniel Veillard 已提交
784 785
}

786
static int virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
D
Daniel Veillard 已提交
787
                            int priority ATTRIBUTE_UNUSED,
788 789
                            const char *funcname ATTRIBUTE_UNUSED,
                            long long linenr ATTRIBUTE_UNUSED,
790 791 792 793
                            const char *timestamp,
                            const char *str,
                            void *data)
{
D
Daniel Veillard 已提交
794 795
    int fd = (long) data;
    int ret;
796
    char *msg;
D
Daniel Veillard 已提交
797 798

    if (fd < 0)
799
        return -1;
800 801 802 803 804 805 806

    if (virAsprintf(&msg, "%s: %s", timestamp, str) < 0)
        return -1;

    ret = safewrite(fd, msg, strlen(msg));
    VIR_FREE(msg);

807
    return ret;
D
Daniel Veillard 已提交
808 809 810 811 812
}

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

813
    VIR_FORCE_CLOSE(fd);
D
Daniel Veillard 已提交
814 815 816
}

static int virLogAddOutputToStderr(int priority) {
817 818
    if (virLogDefineOutput(virLogOutputToFd, NULL, (void *)2L, priority,
                           VIR_LOG_TO_STDERR, NULL, 0) < 0)
819 820
        return -1;
    return 0;
D
Daniel Veillard 已提交
821 822 823 824 825
}

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

826
    fd = open(file, O_CREAT | O_APPEND | O_WRONLY, S_IRUSR | S_IWUSR);
D
Daniel Veillard 已提交
827
    if (fd < 0)
828
        return -1;
D
Daniel Veillard 已提交
829
    if (virLogDefineOutput(virLogOutputToFd, virLogCloseFd, (void *)(long)fd,
830
                           priority, VIR_LOG_TO_FILE, file, 0) < 0) {
831
        VIR_FORCE_CLOSE(fd);
832
        return -1;
D
Daniel Veillard 已提交
833
    }
834
    return 0;
D
Daniel Veillard 已提交
835 836 837
}

#if HAVE_SYSLOG_H
838 839 840 841
static int virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED,
                                int priority,
                                const char *funcname ATTRIBUTE_UNUSED,
                                long long linenr ATTRIBUTE_UNUSED,
842 843 844 845
                                const char *timestamp ATTRIBUTE_UNUSED,
                                const char *str,
                                void *data ATTRIBUTE_UNUSED)
{
D
Daniel Veillard 已提交
846 847 848 849 850 851 852 853 854 855 856 857 858 859 860 861 862 863 864
    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);
865
    return strlen(str);
D
Daniel Veillard 已提交
866 867
}

868 869
static char *current_ident = NULL;

D
Daniel Veillard 已提交
870 871
static void virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) {
    closelog();
872
    VIR_FREE(current_ident);
D
Daniel Veillard 已提交
873 874 875
}

static int virLogAddOutputToSyslog(int priority, const char *ident) {
876 877 878 879 880 881
    /*
     * ident needs to be kept around on Solaris
     */
    VIR_FREE(current_ident);
    current_ident = strdup(ident);
    if (current_ident == NULL)
882
        return -1;
883 884

    openlog(current_ident, 0, 0);
D
Daniel Veillard 已提交
885
    if (virLogDefineOutput(virLogOutputToSyslog, virLogCloseSyslog, NULL,
886
                           priority, VIR_LOG_TO_SYSLOG, ident, 0) < 0) {
D
Daniel Veillard 已提交
887
        closelog();
888
        VIR_FREE(current_ident);
889
        return -1;
D
Daniel Veillard 已提交
890
    }
891
    return 0;
D
Daniel Veillard 已提交
892 893 894 895 896 897 898 899 900 901 902 903 904 905 906 907 908 909 910 911 912 913 914 915 916 917 918 919 920 921 922 923 924
}
#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;
925
    char *abspath;
D
Daniel Veillard 已提交
926
    int prio;
927 928
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
929 930

    if (cur == NULL)
931
        return -1;
D
Daniel Veillard 已提交
932 933 934 935

    virSkipSpaces(&cur);
    while (*cur != 0) {
        prio= virParseNumber(&cur);
936
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
937
            goto cleanup;
D
Daniel Veillard 已提交
938
        if (*cur != ':')
939
            goto cleanup;
D
Daniel Veillard 已提交
940 941 942 943
        cur++;
        if (STREQLEN(cur, "stderr", 6)) {
            cur += 6;
            if (virLogAddOutputToStderr(prio) == 0)
944
                count++;
D
Daniel Veillard 已提交
945 946 947
        } else if (STREQLEN(cur, "syslog", 6)) {
            cur += 6;
            if (*cur != ':')
948
                goto cleanup;
D
Daniel Veillard 已提交
949 950 951 952 953
            cur++;
            str = cur;
            while ((*cur != 0) && (!IS_SPACE(cur)))
                cur++;
            if (str == cur)
954
                goto cleanup;
D
Daniel Veillard 已提交
955 956 957
#if HAVE_SYSLOG_H
            name = strndup(str, cur - str);
            if (name == NULL)
958
                goto cleanup;
D
Daniel Veillard 已提交
959
            if (virLogAddOutputToSyslog(prio, name) == 0)
960
                count++;
D
Daniel Veillard 已提交
961 962 963 964 965
            VIR_FREE(name);
#endif /* HAVE_SYSLOG_H */
        } else if (STREQLEN(cur, "file", 4)) {
            cur += 4;
            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
            name = strndup(str, cur - str);
            if (name == NULL)
975
                goto cleanup;
976 977 978 979 980
            if (virFileAbsPath(name, &abspath) < 0) {
                VIR_FREE(name);
                return -1; /* skip warning here because setting was fine */
            }
            if (virLogAddOutputToFile(prio, abspath) == 0)
981
                count++;
D
Daniel Veillard 已提交
982
            VIR_FREE(name);
983
            VIR_FREE(abspath);
D
Daniel Veillard 已提交
984
        } else {
985
            goto cleanup;
D
Daniel Veillard 已提交
986 987 988
        }
        virSkipSpaces(&cur);
    }
989 990 991
    ret = count;
cleanup:
    if (ret == -1)
992
        VIR_WARN("Ignoring invalid log output setting.");
993
    return ret;
D
Daniel Veillard 已提交
994 995 996 997 998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017
}

/**
 * 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;
1018 1019
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
1020 1021

    if (cur == NULL)
1022
        return -1;
D
Daniel Veillard 已提交
1023 1024 1025 1026

    virSkipSpaces(&cur);
    while (*cur != 0) {
        prio= virParseNumber(&cur);
1027
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
1028
            goto cleanup;
D
Daniel Veillard 已提交
1029
        if (*cur != ':')
1030
            goto cleanup;
D
Daniel Veillard 已提交
1031 1032 1033 1034 1035
        cur++;
        str = cur;
        while ((*cur != 0) && (!IS_SPACE(cur)))
            cur++;
        if (str == cur)
1036
            goto cleanup;
D
Daniel Veillard 已提交
1037 1038
        name = strndup(str, cur - str);
        if (name == NULL)
1039
            goto cleanup;
D
Daniel Veillard 已提交
1040
        if (virLogDefineFilter(name, prio, 0) >= 0)
1041
            count++;
D
Daniel Veillard 已提交
1042 1043 1044
        VIR_FREE(name);
        virSkipSpaces(&cur);
    }
1045 1046 1047
    ret = count;
cleanup:
    if (ret == -1)
1048
        VIR_WARN("Ignoring invalid log filter setting.");
1049
    return ret;
D
Daniel Veillard 已提交
1050
}
1051 1052 1053 1054 1055 1056 1057

/**
 * virLogGetDefaultPriority:
 *
 * Returns the current logging priority level.
 */
int virLogGetDefaultPriority(void) {
1058
    return virLogDefaultPriority;
1059 1060
}

1061 1062 1063 1064 1065 1066 1067 1068 1069 1070 1071 1072 1073
/**
 * 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++) {
1074
        virBufferAsprintf(&filterbuf, "%d:%s ", virLogFilters[i].priority,
1075 1076 1077 1078
                          virLogFilters[i].match);
    }
    virLogUnlock();

1079 1080
    if (virBufferError(&filterbuf)) {
        virBufferFreeAndReset(&filterbuf);
1081
        return NULL;
1082
    }
1083 1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094 1095 1096 1097 1098 1099 1100 1101

    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)
1102
            virBufferAsprintf(&outputbuf, " ");
1103 1104 1105
        switch (dest) {
            case VIR_LOG_TO_SYSLOG:
            case VIR_LOG_TO_FILE:
1106
                virBufferAsprintf(&outputbuf, "%d:%s:%s",
1107 1108 1109 1110 1111
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest),
                                  virLogOutputs[i].name);
                break;
            default:
1112
                virBufferAsprintf(&outputbuf, "%d:%s",
1113 1114 1115 1116 1117 1118
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest));
        }
    }
    virLogUnlock();

1119 1120
    if (virBufferError(&outputbuf)) {
        virBufferFreeAndReset(&outputbuf);
1121
        return NULL;
1122
    }
1123 1124 1125 1126

    return virBufferContentAndReset(&outputbuf);
}

1127 1128 1129 1130 1131 1132
/**
 * virLogGetNbFilters:
 *
 * Returns the current number of defined log filters.
 */
int virLogGetNbFilters(void) {
1133
    return virLogNbFilters;
1134 1135 1136 1137 1138 1139 1140 1141
}

/**
 * virLogGetNbOutputs:
 *
 * Returns the current number of defined log outputs.
 */
int virLogGetNbOutputs(void) {
1142
    return virLogNbOutputs;
1143
}
1144 1145 1146 1147 1148 1149 1150 1151 1152 1153 1154 1155 1156 1157 1158 1159 1160 1161 1162 1163 1164 1165 1166 1167 1168 1169

/**
 * 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
1170
        VIR_WARN("Ignoring invalid log level setting");
1171 1172 1173 1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184 1185 1186 1187 1188

    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)
1189
        virLogParseFilters(debugEnv);
1190 1191
    debugEnv = getenv("LIBVIRT_LOG_OUTPUTS");
    if (debugEnv && *debugEnv)
1192
        virLogParseOutputs(debugEnv);
1193
}