logging.c 33.5 KB
Newer Older
1 2 3
/*
 * logging.c: internal logging and debugging
 *
4
 * Copyright (C) 2008, 2010-2012 Red Hat, Inc.
5 6 7 8 9 10 11 12 13 14 15 16
 *
 * 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
17
 * License along with this library.  If not, see
O
Osier Yang 已提交
18
 * <http://www.gnu.org/licenses/>.
19 20 21 22 23
 *
 */

#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>
34
#include <execinfo.h>
D
Daniel Veillard 已提交
35
#if HAVE_SYSLOG_H
36
# include <syslog.h>
D
Daniel Veillard 已提交
37 38
#endif

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
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;
66
    virLogPriority priority;
67
    unsigned int flags;
D
Daniel Veillard 已提交
68 69 70 71 72 73 74 75 76 77 78 79
};
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 {
80
    bool logVersion;
D
Daniel Veillard 已提交
81 82 83
    void *data;
    virLogOutputFunc f;
    virLogCloseFunc c;
84
    virLogPriority priority;
85 86
    virLogDestination dest;
    const char *name;
D
Daniel Veillard 已提交
87 88 89 90 91 92 93 94 95 96
};
typedef struct _virLogOutput virLogOutput;
typedef virLogOutput *virLogOutputPtr;

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

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

static int virLogResetFilters(void);
static int virLogResetOutputs(void);
101 102 103 104
static void virLogOutputToFd(const char *category,
                             virLogPriority priority,
                             const char *funcname,
                             int linenr,
105 106
                             const char *timestamp,
                             unsigned int flags,
107 108
                             const char *rawstr,
                             const char *str,
109
                             void *data);
D
Daniel Veillard 已提交
110 111 112 113

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

116 117
void
virLogLock(void)
D
Daniel Veillard 已提交
118
{
119
    virMutexLock(&virLogMutex);
D
Daniel Veillard 已提交
120
}
121 122 123 124


void
virLogUnlock(void)
D
Daniel Veillard 已提交
125
{
126
    virMutexUnlock(&virLogMutex);
D
Daniel Veillard 已提交
127 128
}

129 130 131 132

static const char *
virLogOutputString(virLogDestination ldest)
{
133
    switch (ldest) {
134 135 136 137 138 139
    case VIR_LOG_TO_STDERR:
        return "stderr";
    case VIR_LOG_TO_SYSLOG:
        return "syslog";
    case VIR_LOG_TO_FILE:
        return "file";
140
    }
141
    return "unknown";
142
}
D
Daniel Veillard 已提交
143

144 145 146 147

static const char *
virLogPriorityString(virLogPriority lvl)
{
D
Daniel Veillard 已提交
148
    switch (lvl) {
149 150 151 152 153 154 155 156
    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 已提交
157
    }
158
    return "unknown";
D
Daniel Veillard 已提交
159 160 161
}


162 163
static int
virLogOnceInit(void)
164
{
165 166
    const char *pbm = NULL;

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

D
Daniel Veillard 已提交
170
    virLogLock();
171
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
172 173 174 175 176 177
        /*
         * 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;
178
        if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
179 180 181 182 183 184
            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 已提交
185 186 187
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
188
    virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
189
    virLogUnlock();
190
    if (pbm)
191
        VIR_WARN("%s", pbm);
192
    return 0;
D
Daniel Veillard 已提交
193 194
}

195 196
VIR_ONCE_GLOBAL_INIT(virLog)

197

198 199 200 201 202 203 204 205 206 207
/**
 * 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
 */
208 209 210
int
virLogSetBufferSize(int size)
{
211 212 213 214 215 216 217 218
    int ret = 0;
    int oldsize;
    char *oldLogBuffer;
    const char *pbm = NULL;

    if (size < 0)
        size = 0;

219 220 221 222
    if (virLogInitialize() < 0)
        return -1;

    if (size * 1024 == virLogSize)
223 224 225 226 227 228 229
        return ret;

    virLogLock();

    oldsize = virLogSize;
    oldLogBuffer = virLogBuffer;

230
    if (INT_MAX / 1024 <= size) {
231 232 233 234 235 236
        pbm = "Requested log size of %d kB too large\n";
        ret = -1;
        goto error;
    }

    virLogSize = size * 1024;
237
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255
        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;
}

256

D
Daniel Veillard 已提交
257 258 259 260 261 262 263
/**
 * virLogReset:
 *
 * Reset the logging module to its default initial state
 *
 * Returns 0 if successful, and -1 in case or error
 */
264 265 266
int
virLogReset(void)
{
267 268
    if (virLogInitialize() < 0)
        return -1;
D
Daniel Veillard 已提交
269 270 271 272 273 274 275

    virLogLock();
    virLogResetFilters();
    virLogResetOutputs();
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
276
    virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
277
    virLogUnlock();
278
    return 0;
D
Daniel Veillard 已提交
279 280
}

281

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

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

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

323 324 325 326

static void
virLogDumpAllFD(const char *msg, int len)
{
327 328
    int i, found = 0;

329 330 331
    if (len <= 0)
        len = strlen(msg);

332 333
    for (i = 0; i < virLogNbOutputs;i++) {
        if (virLogOutputs[i].f == virLogOutputToFd) {
334
            int fd = (intptr_t) virLogOutputs[i].data;
335 336 337 338 339 340 341 342 343 344 345

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

346

347 348 349 350 351 352 353 354
/**
 * 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 已提交
355
 */
356
void
357 358
virLogEmergencyDumpAll(int signum)
{
359
    int len;
C
Christophe Fergeau 已提交
360
    int oldLogStart, oldLogLen;
D
Daniel Veillard 已提交
361

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

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

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

437

D
Daniel Veillard 已提交
438 439 440 441 442 443 444 445 446 447
/**
 * 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.
 */
448 449 450
int
virLogSetDefaultPriority(virLogPriority priority)
{
451
    if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) {
452
        VIR_WARN("Ignoring invalid log level setting.");
453
        return -1;
454
    }
455 456 457
    if (virLogInitialize() < 0)
        return -1;

D
Daniel Veillard 已提交
458
    virLogDefaultPriority = priority;
459
    return 0;
D
Daniel Veillard 已提交
460 461
}

462

D
Daniel Veillard 已提交
463 464 465 466 467 468 469
/**
 * virLogResetFilters:
 *
 * Removes the set of logging filters defined.
 *
 * Returns the number of filters removed
 */
470 471 472
static int
virLogResetFilters(void)
{
D
Daniel Veillard 已提交
473 474 475 476 477 478
    int i;

    for (i = 0; i < virLogNbFilters;i++)
        VIR_FREE(virLogFilters[i].match);
    VIR_FREE(virLogFilters);
    virLogNbFilters = 0;
479
    return i;
D
Daniel Veillard 已提交
480 481
}

482

D
Daniel Veillard 已提交
483 484 485 486
/**
 * virLogDefineFilter:
 * @match: the pattern to match
 * @priority: the priority to give to messages matching the pattern
487
 * @flags: extra flags, see virLogFilterFlags enum
D
Daniel Veillard 已提交
488 489 490 491 492 493 494 495
 *
 * 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
 */
496 497 498 499
int
virLogDefineFilter(const char *match,
                   virLogPriority priority,
                   unsigned int flags)
500
{
D
Daniel Veillard 已提交
501 502 503
    int i;
    char *mdup = NULL;

504
    virCheckFlags(VIR_LOG_STACK_TRACE, -1);
505

D
Daniel Veillard 已提交
506 507
    if ((match == NULL) || (priority < VIR_LOG_DEBUG) ||
        (priority > VIR_LOG_ERROR))
508
        return -1;
D
Daniel Veillard 已提交
509 510 511 512 513 514 515 516 517 518

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

    mdup = strdup(match);
519
    if (mdup == NULL) {
D
Daniel Veillard 已提交
520 521 522 523 524 525 526 527 528 529 530
        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;
531
    virLogFilters[i].flags = flags;
D
Daniel Veillard 已提交
532 533 534
    virLogNbFilters++;
cleanup:
    virLogUnlock();
535
    return i;
D
Daniel Veillard 已提交
536 537
}

538

D
Daniel Veillard 已提交
539 540 541 542 543 544 545 546 547 548
/**
 * 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.
 */
549 550 551 552
static int
virLogFiltersCheck(const char *input,
                   unsigned int *flags)
{
D
Daniel Veillard 已提交
553 554 555 556 557 558 559
    int ret = 0;
    int i;

    virLogLock();
    for (i = 0;i < virLogNbFilters;i++) {
        if (strstr(input, virLogFilters[i].match)) {
            ret = virLogFilters[i].priority;
560
            *flags = virLogFilters[i].flags;
D
Daniel Veillard 已提交
561 562 563 564
            break;
        }
    }
    virLogUnlock();
565
    return ret;
D
Daniel Veillard 已提交
566 567
}

568

D
Daniel Veillard 已提交
569 570 571 572 573 574 575
/**
 * virLogResetOutputs:
 *
 * Removes the set of logging output defined.
 *
 * Returns the number of output removed
 */
576 577 578
static int
virLogResetOutputs(void)
{
D
Daniel Veillard 已提交
579 580 581 582 583
    int i;

    for (i = 0;i < virLogNbOutputs;i++) {
        if (virLogOutputs[i].c != NULL)
            virLogOutputs[i].c(virLogOutputs[i].data);
584
        VIR_FREE(virLogOutputs[i].name);
D
Daniel Veillard 已提交
585 586 587 588
    }
    VIR_FREE(virLogOutputs);
    i = virLogNbOutputs;
    virLogNbOutputs = 0;
589
    return i;
D
Daniel Veillard 已提交
590 591
}

592

D
Daniel Veillard 已提交
593 594 595
/**
 * virLogDefineOutput:
 * @f: the function to call to output a message
596
 * @c: the function to call to close the output (or NULL)
D
Daniel Veillard 已提交
597 598
 * @data: extra data passed as first arg to the function
 * @priority: minimal priority for this filter, use 0 for none
599 600
 * @dest: where to send output of this priority
 * @name: optional name data associated with an output
D
Daniel Veillard 已提交
601 602 603 604 605 606 607
 * @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
 */
608 609 610 611 612 613 614 615
int
virLogDefineOutput(virLogOutputFunc f,
                   virLogCloseFunc c,
                   void *data,
                   virLogPriority priority,
                   virLogDestination dest,
                   const char *name,
                   unsigned int flags)
616
{
D
Daniel Veillard 已提交
617
    int ret = -1;
618
    char *ndup = NULL;
D
Daniel Veillard 已提交
619

620 621
    virCheckFlags(0, -1);

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

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

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

651

652 653 654
static int
virLogFormatString(char **msg,
                   const char *funcname,
655
                   int linenr,
656
                   virLogPriority priority,
657 658 659
                   const char *str)
{
    int ret;
660 661 662 663 664 665 666 667

    /*
     * 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.
     */
668
    if ((funcname != NULL)) {
669
        ret = virAsprintf(msg, "%d: %s : %s:%d : %s\n",
670 671
                          virThreadSelfID(), virLogPriorityString(priority),
                          funcname, linenr, str);
672
    } else {
673 674 675
        ret = virAsprintf(msg, "%d: %s : %s\n",
                          virThreadSelfID(), virLogPriorityString(priority),
                          str);
676 677 678 679
    }
    return ret;
}

680

681
static int
682 683
virLogVersionString(const char **rawmsg,
                    char **msg)
684 685 686 687 688 689 690 691 692 693 694 695 696 697
{
#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

698
    *rawmsg = LOG_VERSION_STRING;
699
    return virLogFormatString(msg, NULL, 0, VIR_LOG_INFO, LOG_VERSION_STRING);
700 701
}

702

D
Daniel Veillard 已提交
703 704 705 706
/**
 * virLogMessage:
 * @category: where is that message coming from
 * @priority: the priority level
707 708
 * @funcname: the function emitting the (debug) message
 * @linenr: line where the message was emitted
D
Daniel Veillard 已提交
709 710 711 712
 * @flags: extra flags, 1 if coming from the error handler
 * @fmt: the string format
 * @...: the arguments
 *
E
Eric Blake 已提交
713
 * Call the libvirt logger with some information. Based on the configuration
D
Daniel Veillard 已提交
714 715
 * the message may be stored, sent to output or just discarded
 */
716 717 718 719 720 721 722
void
virLogMessage(const char *category,
              virLogPriority priority,
              const char *funcname,
              int linenr,
              unsigned int flags,
              const char *fmt, ...)
723 724 725 726 727 728 729
{
    va_list ap;
    va_start(ap, fmt);
    virLogVMessage(category, priority, funcname, linenr, flags, fmt, ap);
    va_end(ap);
}

730

731 732 733 734 735 736 737 738 739 740 741 742 743
/**
 * virLogVMessage:
 * @category: where is that message coming from
 * @priority: the priority level
 * @funcname: the function emitting the (debug) message
 * @linenr: line where the message was emitted
 * @flags: extra flags, 1 if coming from the error handler
 * @fmt: the string format
 * @vargs: format args
 *
 * Call the libvirt logger with some information. Based on the configuration
 * the message may be stored, sent to output or just discarded
 */
744 745 746 747 748 749 750 751
void
virLogVMessage(const char *category,
               virLogPriority priority,
               const char *funcname,
               int linenr,
               unsigned int flags,
               const char *fmt,
               va_list vargs)
752
{
753
    static bool logVersionStderr = true;
D
Daniel Veillard 已提交
754
    char *str = NULL;
755
    char *msg = NULL;
756
    char timestamp[VIR_TIME_STRING_BUFLEN];
757
    int fprio, i, ret;
758
    int saved_errno = errno;
759
    int emit = 1;
760
    unsigned int filterflags = 0;
D
Daniel Veillard 已提交
761

762 763
    if (virLogInitialize() < 0)
        return;
D
Daniel Veillard 已提交
764 765

    if (fmt == NULL)
766
        goto cleanup;
D
Daniel Veillard 已提交
767 768 769 770

    /*
     * check against list of specific logging patterns
     */
771
    fprio = virLogFiltersCheck(category, &filterflags);
D
Daniel Veillard 已提交
772 773
    if (fprio == 0) {
        if (priority < virLogDefaultPriority)
774
            emit = 0;
775
    } else if (priority < fprio) {
776
        emit = 0;
777
    }
D
Daniel Veillard 已提交
778

779 780 781
    if ((emit == 0) && ((virLogBuffer == NULL) || (virLogSize <= 0)))
        goto cleanup;

D
Daniel Veillard 已提交
782 783 784
    /*
     * serialize the error message, add level and timestamp
     */
785
    if (virVasprintf(&str, fmt, vargs) < 0) {
786
        goto cleanup;
E
Eric Blake 已提交
787
    }
D
Daniel Veillard 已提交
788

789
    ret = virLogFormatString(&msg, funcname, linenr, priority, str);
790 791
    if (ret < 0)
        goto cleanup;
D
Daniel Veillard 已提交
792

793 794
    if (virTimeStringNowRaw(timestamp) < 0)
        timestamp[0] = '\0';
795

D
Daniel Veillard 已提交
796
    /*
797 798
     * 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 已提交
799 800 801 802 803
     * 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.
     */
804 805 806 807
    virLogLock();
    virLogStr(timestamp);
    virLogStr(msg);
    virLogUnlock();
808 809 810
    if (emit == 0)
        goto cleanup;

D
Daniel Veillard 已提交
811
    virLogLock();
812
    for (i = 0; i < virLogNbOutputs; i++) {
813 814
        if (priority >= virLogOutputs[i].priority) {
            if (virLogOutputs[i].logVersion) {
815
                const char *rawver;
816
                char *ver = NULL;
817
                if (virLogVersionString(&rawver, &ver) >= 0)
818 819
                    virLogOutputs[i].f(category, VIR_LOG_INFO,
                                       __func__, __LINE__,
820
                                       timestamp, 0, rawver, ver,
821 822 823 824
                                       virLogOutputs[i].data);
                VIR_FREE(ver);
                virLogOutputs[i].logVersion = false;
            }
825
            virLogOutputs[i].f(category, priority, funcname, linenr,
826
                               timestamp, filterflags,
827
                               str, msg, virLogOutputs[i].data);
828
        }
D
Daniel Veillard 已提交
829
    }
830 831
    if ((virLogNbOutputs == 0) && (flags != 1)) {
        if (logVersionStderr) {
832
            const char *rawver;
833
            char *ver = NULL;
834
            if (virLogVersionString(&rawver, &ver) >= 0)
835 836
                virLogOutputToFd(category, VIR_LOG_INFO,
                                 __func__, __LINE__,
837
                                 timestamp, 0, rawver, ver,
838
                                 (void *) STDERR_FILENO);
839 840 841
            VIR_FREE(ver);
            logVersionStderr = false;
        }
842
        virLogOutputToFd(category, priority, funcname, linenr,
843
                         timestamp, filterflags,
844
                         str, msg, (void *) STDERR_FILENO);
845
    }
D
Daniel Veillard 已提交
846 847
    virLogUnlock();

848
cleanup:
849
    VIR_FREE(str);
850
    VIR_FREE(msg);
851
    errno = saved_errno;
D
Daniel Veillard 已提交
852 853
}

854

855 856
static void
virLogStackTraceToFd(int fd)
857 858 859 860 861
{
    void *array[100];
    int size;
    static bool doneWarning = false;
    const char *msg = "Stack trace not available on this platform\n";
862 863 864 865 866 867 868

#define STRIP_DEPTH 3
    size = backtrace(array, ARRAY_CARDINALITY(array));
    if (size) {
        backtrace_symbols_fd(array +  STRIP_DEPTH, size - STRIP_DEPTH, fd);
        ignore_value(safewrite(fd, "\n", 1));
    } else if (!doneWarning) {
869 870 871
        ignore_value(safewrite(fd, msg, strlen(msg)));
        doneWarning = true;
    }
872
#undef STRIP_DEPTH
873 874
}

875 876 877 878 879 880 881 882 883 884
static void
virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
                 virLogPriority priority ATTRIBUTE_UNUSED,
                 const char *funcname ATTRIBUTE_UNUSED,
                 int linenr ATTRIBUTE_UNUSED,
                 const char *timestamp,
                 unsigned int flags,
                 const char *rawstr ATTRIBUTE_UNUSED,
                 const char *str,
                 void *data)
885
{
886
    int fd = (intptr_t) data;
887
    char *msg;
D
Daniel Veillard 已提交
888 889

    if (fd < 0)
890
        return;
891 892

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

895
    ignore_value(safewrite(fd, msg, strlen(msg)));
896 897
    VIR_FREE(msg);

898 899
    if (flags & VIR_LOG_STACK_TRACE)
        virLogStackTraceToFd(fd);
D
Daniel Veillard 已提交
900 901
}

902 903 904

static void
virLogCloseFd(void *data)
905
{
906
    int fd = (intptr_t) data;
D
Daniel Veillard 已提交
907

908
    VIR_LOG_CLOSE(fd);
D
Daniel Veillard 已提交
909 910
}

911 912 913 914

static int
virLogAddOutputToStderr(virLogPriority priority)
{
915 916
    if (virLogDefineOutput(virLogOutputToFd, NULL, (void *)2L, priority,
                           VIR_LOG_TO_STDERR, NULL, 0) < 0)
917 918
        return -1;
    return 0;
D
Daniel Veillard 已提交
919 920
}

921 922 923 924 925

static int
virLogAddOutputToFile(virLogPriority priority,
                      const char *file)
{
D
Daniel Veillard 已提交
926 927
    int fd;

928
    fd = open(file, O_CREAT | O_APPEND | O_WRONLY, S_IRUSR | S_IWUSR);
D
Daniel Veillard 已提交
929
    if (fd < 0)
930
        return -1;
931 932
    if (virLogDefineOutput(virLogOutputToFd, virLogCloseFd,
                           (void *)(intptr_t)fd,
933
                           priority, VIR_LOG_TO_FILE, file, 0) < 0) {
934
        VIR_FORCE_CLOSE(fd);
935
        return -1;
D
Daniel Veillard 已提交
936
    }
937
    return 0;
D
Daniel Veillard 已提交
938 939
}

940

D
Daniel Veillard 已提交
941
#if HAVE_SYSLOG_H
942 943
static int
virLogPrioritySyslog(virLogPriority priority)
944 945 946 947 948 949 950 951 952 953 954 955 956 957 958
{
    switch (priority) {
    case VIR_LOG_DEBUG:
        return LOG_DEBUG;
    case VIR_LOG_INFO:
        return LOG_INFO;
    case VIR_LOG_WARN:
        return LOG_WARNING;
    case VIR_LOG_ERROR:
        return LOG_ERR;
    default:
        return LOG_ERR;
    }
}

959 960 961 962 963 964 965 966 967 968 969

static void
virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED,
                     virLogPriority priority,
                     const char *funcname ATTRIBUTE_UNUSED,
                     int linenr ATTRIBUTE_UNUSED,
                     const char *timestamp ATTRIBUTE_UNUSED,
                     unsigned int flags,
                     const char *rawstr ATTRIBUTE_UNUSED,
                     const char *str,
                     void *data ATTRIBUTE_UNUSED)
970
{
971
    virCheckFlags(VIR_LOG_STACK_TRACE,);
972

973
    syslog(virLogPrioritySyslog(priority), "%s", str);
D
Daniel Veillard 已提交
974 975
}

976 977
static char *current_ident = NULL;

978 979 980 981

static void
virLogCloseSyslog(void *data ATTRIBUTE_UNUSED)
{
D
Daniel Veillard 已提交
982
    closelog();
983
    VIR_FREE(current_ident);
D
Daniel Veillard 已提交
984 985
}

986 987 988 989 990

static int
virLogAddOutputToSyslog(virLogPriority priority,
                        const char *ident)
{
991 992 993 994 995 996
    /*
     * ident needs to be kept around on Solaris
     */
    VIR_FREE(current_ident);
    current_ident = strdup(ident);
    if (current_ident == NULL)
997
        return -1;
998 999

    openlog(current_ident, 0, 0);
D
Daniel Veillard 已提交
1000
    if (virLogDefineOutput(virLogOutputToSyslog, virLogCloseSyslog, NULL,
1001
                           priority, VIR_LOG_TO_SYSLOG, ident, 0) < 0) {
D
Daniel Veillard 已提交
1002
        closelog();
1003
        VIR_FREE(current_ident);
1004
        return -1;
D
Daniel Veillard 已提交
1005
    }
1006
    return 0;
D
Daniel Veillard 已提交
1007 1008 1009 1010 1011 1012 1013
}
#endif /* HAVE_SYSLOG_H */

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

1014

D
Daniel Veillard 已提交
1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036 1037
/**
 * 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
 */
1038 1039 1040
int
virLogParseOutputs(const char *outputs)
{
D
Daniel Veillard 已提交
1041 1042
    const char *cur = outputs, *str;
    char *name;
1043
    char *abspath;
1044
    virLogPriority prio;
1045 1046
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
1047 1048

    if (cur == NULL)
1049
        return -1;
D
Daniel Veillard 已提交
1050 1051 1052 1053

    virSkipSpaces(&cur);
    while (*cur != 0) {
        prio= virParseNumber(&cur);
1054
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
1055
            goto cleanup;
D
Daniel Veillard 已提交
1056
        if (*cur != ':')
1057
            goto cleanup;
D
Daniel Veillard 已提交
1058 1059 1060 1061
        cur++;
        if (STREQLEN(cur, "stderr", 6)) {
            cur += 6;
            if (virLogAddOutputToStderr(prio) == 0)
1062
                count++;
D
Daniel Veillard 已提交
1063 1064 1065
        } else if (STREQLEN(cur, "syslog", 6)) {
            cur += 6;
            if (*cur != ':')
1066
                goto cleanup;
D
Daniel Veillard 已提交
1067 1068 1069 1070 1071
            cur++;
            str = cur;
            while ((*cur != 0) && (!IS_SPACE(cur)))
                cur++;
            if (str == cur)
1072
                goto cleanup;
D
Daniel Veillard 已提交
1073 1074 1075
#if HAVE_SYSLOG_H
            name = strndup(str, cur - str);
            if (name == NULL)
1076
                goto cleanup;
D
Daniel Veillard 已提交
1077
            if (virLogAddOutputToSyslog(prio, name) == 0)
1078
                count++;
D
Daniel Veillard 已提交
1079 1080 1081 1082 1083
            VIR_FREE(name);
#endif /* HAVE_SYSLOG_H */
        } else if (STREQLEN(cur, "file", 4)) {
            cur += 4;
            if (*cur != ':')
1084
                goto cleanup;
D
Daniel Veillard 已提交
1085 1086 1087 1088 1089
            cur++;
            str = cur;
            while ((*cur != 0) && (!IS_SPACE(cur)))
                cur++;
            if (str == cur)
1090
                goto cleanup;
D
Daniel Veillard 已提交
1091 1092
            name = strndup(str, cur - str);
            if (name == NULL)
1093
                goto cleanup;
1094 1095 1096 1097 1098
            if (virFileAbsPath(name, &abspath) < 0) {
                VIR_FREE(name);
                return -1; /* skip warning here because setting was fine */
            }
            if (virLogAddOutputToFile(prio, abspath) == 0)
1099
                count++;
D
Daniel Veillard 已提交
1100
            VIR_FREE(name);
1101
            VIR_FREE(abspath);
D
Daniel Veillard 已提交
1102
        } else {
1103
            goto cleanup;
D
Daniel Veillard 已提交
1104 1105 1106
        }
        virSkipSpaces(&cur);
    }
1107 1108 1109
    ret = count;
cleanup:
    if (ret == -1)
1110
        VIR_WARN("Ignoring invalid log output setting.");
1111
    return ret;
D
Daniel Veillard 已提交
1112 1113
}

1114

D
Daniel Veillard 已提交
1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131 1132
/**
 * 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
 */
1133 1134 1135
int
virLogParseFilters(const char *filters)
{
D
Daniel Veillard 已提交
1136 1137
    const char *cur = filters, *str;
    char *name;
1138
    virLogPriority prio;
1139 1140
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
1141 1142

    if (cur == NULL)
1143
        return -1;
D
Daniel Veillard 已提交
1144 1145 1146

    virSkipSpaces(&cur);
    while (*cur != 0) {
1147
        unsigned int flags = 0;
D
Daniel Veillard 已提交
1148
        prio= virParseNumber(&cur);
1149
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
1150
            goto cleanup;
D
Daniel Veillard 已提交
1151
        if (*cur != ':')
1152
            goto cleanup;
D
Daniel Veillard 已提交
1153
        cur++;
1154 1155 1156 1157
        if (*cur == '+') {
            flags |= VIR_LOG_STACK_TRACE;
            cur++;
        }
D
Daniel Veillard 已提交
1158 1159 1160 1161
        str = cur;
        while ((*cur != 0) && (!IS_SPACE(cur)))
            cur++;
        if (str == cur)
1162
            goto cleanup;
D
Daniel Veillard 已提交
1163 1164
        name = strndup(str, cur - str);
        if (name == NULL)
1165
            goto cleanup;
1166
        if (virLogDefineFilter(name, prio, flags) >= 0)
1167
            count++;
D
Daniel Veillard 已提交
1168 1169 1170
        VIR_FREE(name);
        virSkipSpaces(&cur);
    }
1171 1172 1173
    ret = count;
cleanup:
    if (ret == -1)
1174
        VIR_WARN("Ignoring invalid log filter setting.");
1175
    return ret;
D
Daniel Veillard 已提交
1176
}
1177

1178

1179 1180 1181 1182 1183
/**
 * virLogGetDefaultPriority:
 *
 * Returns the current logging priority level.
 */
1184 1185 1186
virLogPriority
virLogGetDefaultPriority(void)
{
1187
    return virLogDefaultPriority;
1188 1189
}

1190

1191 1192 1193 1194 1195 1196 1197
/**
 * virLogGetFilters:
 *
 * Returns a string listing the current filters, in the format originally
 * specified in the config file or environment. Caller must free the
 * result.
 */
1198 1199 1200
char *
virLogGetFilters(void)
{
1201 1202 1203 1204 1205
    int i;
    virBuffer filterbuf = VIR_BUFFER_INITIALIZER;

    virLogLock();
    for (i = 0; i < virLogNbFilters; i++) {
1206 1207 1208 1209 1210 1211
        const char *sep = ":";
        if (virLogFilters[i].flags & VIR_LOG_STACK_TRACE)
            sep = ":+";
        virBufferAsprintf(&filterbuf, "%d%s%s ",
                          virLogFilters[i].priority,
                          sep,
1212 1213 1214 1215
                          virLogFilters[i].match);
    }
    virLogUnlock();

1216 1217
    if (virBufferError(&filterbuf)) {
        virBufferFreeAndReset(&filterbuf);
1218
        return NULL;
1219
    }
1220 1221 1222 1223

    return virBufferContentAndReset(&filterbuf);
}

1224

1225 1226 1227 1228 1229 1230 1231
/**
 * virLogGetOutputs:
 *
 * Returns a string listing the current outputs, in the format originally
 * specified in the config file or environment. Caller must free the
 * result.
 */
1232 1233 1234
char *
virLogGetOutputs(void)
{
1235 1236 1237 1238 1239
    int i;
    virBuffer outputbuf = VIR_BUFFER_INITIALIZER;

    virLogLock();
    for (i = 0; i < virLogNbOutputs; i++) {
1240
        virLogDestination dest = virLogOutputs[i].dest;
1241
        if (i)
1242
            virBufferAsprintf(&outputbuf, " ");
1243 1244 1245
        switch (dest) {
            case VIR_LOG_TO_SYSLOG:
            case VIR_LOG_TO_FILE:
1246
                virBufferAsprintf(&outputbuf, "%d:%s:%s",
1247 1248 1249 1250 1251
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest),
                                  virLogOutputs[i].name);
                break;
            default:
1252
                virBufferAsprintf(&outputbuf, "%d:%s",
1253 1254 1255 1256 1257 1258
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest));
        }
    }
    virLogUnlock();

1259 1260
    if (virBufferError(&outputbuf)) {
        virBufferFreeAndReset(&outputbuf);
1261
        return NULL;
1262
    }
1263 1264 1265 1266

    return virBufferContentAndReset(&outputbuf);
}

1267

1268 1269 1270 1271 1272
/**
 * virLogGetNbFilters:
 *
 * Returns the current number of defined log filters.
 */
1273 1274 1275
int
virLogGetNbFilters(void)
{
1276
    return virLogNbFilters;
1277 1278
}

1279

1280 1281 1282 1283 1284
/**
 * virLogGetNbOutputs:
 *
 * Returns the current number of defined log outputs.
 */
1285 1286 1287
int
virLogGetNbOutputs(void)
{
1288
    return virLogNbOutputs;
1289
}
1290

1291

1292 1293 1294 1295 1296 1297 1298 1299 1300 1301 1302 1303 1304
/**
 * 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.
 */
1305 1306 1307
int
virLogParseDefaultPriority(const char *priority)
{
1308 1309 1310 1311 1312 1313 1314 1315 1316 1317 1318
    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
1319
        VIR_WARN("Ignoring invalid log level setting");
1320 1321 1322 1323

    return ret;
}

1324

1325 1326 1327 1328 1329 1330
/**
 * virLogSetFromEnv:
 *
 * Sets virLogDefaultPriority, virLogFilters and virLogOutputs based on
 * environment variables.
 */
1331 1332 1333
void
virLogSetFromEnv(void)
{
1334 1335 1336 1337 1338 1339 1340
    char *debugEnv;

    debugEnv = getenv("LIBVIRT_DEBUG");
    if (debugEnv && *debugEnv)
        virLogParseDefaultPriority(debugEnv);
    debugEnv = getenv("LIBVIRT_LOG_FILTERS");
    if (debugEnv && *debugEnv)
1341
        virLogParseFilters(debugEnv);
1342 1343
    debugEnv = getenv("LIBVIRT_LOG_OUTPUTS");
    if (debugEnv && *debugEnv)
1344
        virLogParseOutputs(debugEnv);
1345
}