lib/util/debug.c

   1 /*
   2    Unix SMB/CIFS implementation.
   3    Samba utility functions
   4    Copyright (C) Andrew Tridgell 1992-1998
   5    Copyright (C) Elrond               2002
   6    Copyright (C) Simo Sorce           2002
   7
   8    This program is free software; you can redistribute it and/or modify
   9    it under the terms of the GNU General Public License as published by
  10    the Free Software Foundation; either version 3 of the License, or
  11    (at your option) any later version.
  12
  13    This program is distributed in the hope that it will be useful,
  14    but WITHOUT ANY WARRANTY; without even the implied warranty of
  15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  16    GNU General Public License for more details.
  17
  18    You should have received a copy of the GNU General Public License
  19    along with this program.  If not, see <http://www.gnu.org/licenses/>.
  20 */
  21
  22 #include "replace.h"
  23 #include <talloc.h>
  24 #include "system/filesys.h"
  25 #include "system/syslog.h"
  26 #include "system/locale.h"
  27 #include "system/network.h"
  28 #include "system/time.h"
  29 #include "time_basic.h"
  30 #include "close_low_fd.h"
  31 #include "memory.h"
  32 #include "util_strlist.h" /* LIST_SEP */
  33 #include "blocking.h"
  34 #include "debug.h"
  35 #include <assert.h>
  36
  37 /* define what facility to use for syslog */
  38 #ifndef SYSLOG_FACILITY
  39 #define SYSLOG_FACILITY LOG_DAEMON
  40 #endif
  41
  42 /* -------------------------------------------------------------------------- **
  43  * Defines...
  44  */
  45
  46 /*
  47  * format_bufr[FORMAT_BUFR_SIZE - 1] should always be reserved
  48  * for a terminating null byte.
  49  */
  50 #define FORMAT_BUFR_SIZE 4096
  51
  52 /* -------------------------------------------------------------------------- **
  53  * This module implements Samba's debugging utility.
  54  *
  55  * The syntax of a debugging log file is represented as:
  56  *
  57  *  <debugfile> :== { <debugmsg> }
  58  *
  59  *  <debugmsg>  :== <debughdr> '\n' <debugtext>
  60  *
  61  *  <debughdr>  :== '[' TIME ',' LEVEL ']' [ [FILENAME ':'] [FUNCTION '()'] ]
  62  *
  63  *  <debugtext> :== { <debugline> }
  64  *
  65  *  <debugline> :== TEXT '\n'
  66  *
  67  * TEXT     is a string of characters excluding the newline character.
  68  * LEVEL    is the DEBUG level of the message (an integer in the range 0..10).
  69  * TIME     is a timestamp.
  70  * FILENAME is the name of the file from which the debug message was generated.
  71  * FUNCTION is the function from which the debug message was generated.
  72  *
  73  * Basically, what that all means is:
  74  *
  75  * - A debugging log file is made up of debug messages.
  76  *
  77  * - Each debug message is made up of a header and text.  The header is
  78  *   separated from the text by a newline.
  79  *
  80  * - The header begins with the timestamp and debug level of the message
  81  *   enclosed in brackets.  The filename and function from which the
  82  *   message was generated may follow.  The filename is terminated by a
  83  *   colon, and the function name is terminated by parenthesis.
  84  *
  85  * - The message text is made up of zero or more lines, each terminated by
  86  *   a newline.
  87  */
  88
  89 /* state variables for the debug system */
  90 static struct {
  91         bool initialized;
  92         enum debug_logtype logtype; /* The type of logging we are doing: eg stdout, file, stderr */
  93         char prog_name[255];
  94         char hostname[HOST_NAME_MAX+1];
  95         bool reopening_logs;
  96         bool schedule_reopen_logs;
  97         int forced_log_priority;
  98
  99         struct debug_settings settings;
 100         debug_callback_fn callback;
 101         void *callback_private;
 102         char header_str[300];
 103         size_t hs_len;
 104 } state = {
 105         .settings = {
 106                 .timestamp_logs = true
 107         },
 108 };
 109
 110 struct debug_class {
 111         /*
 112          * The debug loglevel of the class.
 113          */
 114         int loglevel;
 115
 116         /*
 117          * An optional class specific logfile, may be NULL in which case the
 118          * "global" logfile is used and fd is -1.
 119          */
 120         char *logfile;
 121         int fd;
 122         /* inode number of the logfile to detect logfile rotation */
 123         ino_t ino;
 124 };
 125
 126 /*
 127  * default_classname_table[] is read in from debug-classname-table.c
 128  * so that test_logging.c can use it too.
 129  */
 130 #include "lib/util/debug-classes/debug-classname-table.c"
 131
 132 /*
 133  * This is to allow reading of dbgc_config before the debug
 134  * system has been initialized.
 135  */
 136 static struct debug_class debug_class_list_initial[ARRAY_SIZE(default_classname_table)] = {
 137         [DBGC_ALL] = { .fd = 2 },
 138 };
 139
 140 static size_t debug_num_classes = 0;
 141 static struct debug_class *dbgc_config = debug_class_list_initial;
 142
 143 static int current_msg_level = 0;
 144 static int current_msg_class = 0;
 145
 146 /*
 147  * DBG_DEV(): when and how to user it.
 148  *
 149  * As a developer, you sometimes want verbose logging between point A and
 150  * point B, where the relationship between these points is not easily defined
 151  * in terms of the call stack.
 152  *
 153  * For example, you might be interested in what is going on in functions in
 154  * lib/util/util_str.c in an ldap worker process after a particular query. If
 155  * you use gdb, something will time out and you won't get the full
 156  * conversation. If you add fprintf() or DBG_ERR()s to util_str.c, you'll get
 157  * a massive flood, and there's a chance one will accidentally slip into a
 158  * release and the whole world will flood. DBG_DEV is a solution.
 159  *
 160  * On start-up, DBG_DEV() is switched OFF. Nothing is printed.
 161  *
 162  * 1. Add `DBG_DEV("formatted msg %d, etc\n", i);` where needed.
 163  *
 164  * 2. At each point you want to start debugging, add `debug_developer_enable()`.
 165  *
 166  * 3. At each point you want debugging to stop, add `debug_developer_disable()`.
 167  *
 168  * In DEVELOPER builds, the message will be printed at level 0, as with
 169  * DBG_ERR(). In production builds, the macro resolves to nothing.
 170  *
 171  * The messages are printed with a "<function_name>:DEV:<pid>:" prefix.
 172  */
 173
 174 static bool debug_developer_is_enabled = false;
 175
 176 bool debug_developer_enabled(void)
 177 {
 178         return debug_developer_is_enabled;
 179 }
 180
 181 /*
 182  * debug_developer_disable() will turn DBG_DEV() on in the current
 183  * process and children.
 184  */
 185 void debug_developer_enable(void)
 186 {
 187         debug_developer_is_enabled = true;
 188 }
 189
 190 /*
 191  * debug_developer_disable() will make DBG_DEV() do nothing in the current
 192  * process (and children).
 193  */
 194 void debug_developer_disable(void)
 195 {
 196         debug_developer_is_enabled = false;
 197 }
 198
 199 /*
 200  * Within debug.c, DBG_DEV() always writes to stderr, because some functions
 201  * here will attempt infinite recursion with normal DEBUG macros.
 202  */
 203 #ifdef DEVELOPER
 204 #undef DBG_DEV
 205 #define DBG_DEV(fmt, ...)                                               \
 206         (void)((debug_developer_enabled())                              \
 207                && (fprintf(stderr, "%s:DEV:%d: " fmt "%s",              \
 208                            __func__, getpid(), ##__VA_ARGS__, "")) )
 209 #endif
 210
 211
 212 #if defined(WITH_SYSLOG) || defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
 213 static int debug_level_to_priority(int level)
 214 {
 215         /*
 216          * map debug levels to syslog() priorities
 217          */
 218         static const int priority_map[] = {
 219                 LOG_ERR,     /* 0 */
 220                 LOG_WARNING, /* 1 */
 221                 LOG_NOTICE,  /* 2 */
 222                 LOG_NOTICE,  /* 3 */
 223                 LOG_NOTICE,  /* 4 */
 224                 LOG_NOTICE,  /* 5 */
 225                 LOG_INFO,    /* 6 */
 226                 LOG_INFO,    /* 7 */
 227                 LOG_INFO,    /* 8 */
 228                 LOG_INFO,    /* 9 */
 229         };
 230         int priority;
 231
 232         if (state.forced_log_priority != -1) {
 233                 level = state.forced_log_priority;
 234         }
 235
 236         if (level < 0 || (size_t)level >= ARRAY_SIZE(priority_map))
 237                 priority = LOG_DEBUG;
 238         else
 239                 priority = priority_map[level];
 240
 241         return priority;
 242 }
 243 #endif
 244
 245 /* -------------------------------------------------------------------------- **
 246  * Debug backends. When logging to DEBUG_FILE, send the log entries to
 247  * all active backends.
 248  */
 249
 250 static void debug_file_log(int msg_level, const char *msg, size_t msg_len)
 251 {
 252         struct iovec iov[] = {
 253                 {
 254                         .iov_base = discard_const(state.header_str),
 255                         .iov_len = state.hs_len,
 256                 },
 257                 {
 258                         .iov_base = discard_const(msg),
 259                         .iov_len = msg_len,
 260                 },
 261         };
 262         ssize_t ret;
 263         int fd;
 264
 265         check_log_size();
 266
 267         if (dbgc_config[current_msg_class].fd != -1) {
 268                 fd = dbgc_config[current_msg_class].fd;
 269         } else {
 270                 fd = dbgc_config[DBGC_ALL].fd;
 271         }
 272
 273         do {
 274                 ret = writev(fd, iov, ARRAY_SIZE(iov));
 275         } while (ret == -1 && errno == EINTR);
 276 }
 277
 278 #ifdef WITH_SYSLOG
 279 static void debug_syslog_reload(bool enabled, bool previously_enabled,
 280                                 const char *prog_name, char *option)
 281 {
 282         if (enabled && !previously_enabled) {
 283                 const char *ident = NULL;
 284                 if ((prog_name != NULL) && (prog_name[0] != '\0')) {
 285                         ident = prog_name;
 286                 }
 287 #ifdef LOG_DAEMON
 288                 openlog(ident, LOG_PID, SYSLOG_FACILITY);
 289 #else
 290                 /* for old systems that have no facility codes. */
 291                 openlog(ident, LOG_PID);
 292 #endif
 293                 return;
 294         }
 295
 296         if (!enabled && previously_enabled) {
 297                 closelog();
 298         }
 299 }
 300
 301 static void debug_syslog_log(int msg_level, const char *msg, size_t msg_len)
 302 {
 303         int priority;
 304
 305         priority = debug_level_to_priority(msg_level);
 306
 307         /*
 308          * Specify the facility to interoperate with other syslog
 309          * callers (vfs_full_audit for example).
 310          */
 311         priority |= SYSLOG_FACILITY;
 312
 313         if (state.hs_len > 0) {
 314                 syslog(priority, "%s", state.header_str);
 315         }
 316         syslog(priority, "%s", msg);
 317 }
 318 #endif /* WITH_SYSLOG */
 319
 320 #if defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
 321 #include <systemd/sd-journal.h>
 322 static void debug_systemd_log(int msg_level, const char *msg, size_t msg_len)
 323 {
 324         if (state.hs_len > 0) {
 325                 size_t len = state.hs_len;
 326
 327                 if (state.header_str[len - 1] == '\n') {
 328                         len -= 1;
 329                 }
 330
 331                 sd_journal_send("MESSAGE=%.*s",
 332                                 (int)len,
 333                                 state.header_str,
 334                                 "PRIORITY=%d",
 335                                 debug_level_to_priority(msg_level),
 336                                 "LEVEL=%d",
 337                                 msg_level,
 338                                 NULL);
 339         }
 340
 341         if ((msg_len > 0) && (msg[msg_len - 1] == '\n')) {
 342                 msg_len -= 1;
 343         }
 344
 345         sd_journal_send("MESSAGE=%.*s",
 346                         (int)msg_len,
 347                         msg,
 348                         "PRIORITY=%d",
 349                         debug_level_to_priority(msg_level),
 350                         "LEVEL=%d",
 351                         msg_level,
 352                         NULL);
 353 }
 354 #endif
 355
 356 #ifdef HAVE_LTTNG_TRACEF
 357 #include <lttng/tracef.h>
 358 static void debug_lttng_log(int msg_level, const char *msg, size_t msg_len)
 359 {
 360         if (state.hs_len > 0) {
 361                 size_t len = state.hs_len;
 362
 363                 if (state.header_str[len - 1] == '\n') {
 364                         len -= 1;
 365                 }
 366
 367                 tracef("%.*s", (int)len, state.header_str);
 368         }
 369
 370         if ((msg_len > 0) && (msg[msg_len - 1] == '\n')) {
 371                 msg_len -= 1;
 372         }
 373         tracef("%.*s", (int)msg_len, msg);
 374 }
 375 #endif /* WITH_LTTNG_TRACEF */
 376
 377 #ifdef HAVE_GPFS
 378 #include "gpfswrap.h"
 379 static void debug_gpfs_reload(bool enabled, bool previously_enabled,
 380                               const char *prog_name, char *option)
 381 {
 382         if (enabled) {
 383                 gpfswrap_init();
 384         }
 385
 386         if (enabled && !previously_enabled) {
 387                 gpfswrap_init_trace();
 388                 return;
 389         }
 390
 391         if (!enabled && previously_enabled) {
 392                 gpfswrap_fini_trace();
 393                 return;
 394         }
 395
 396         if (enabled) {
 397                 /*
 398                  * Trigger GPFS library to adjust state if necessary.
 399                  */
 400                 gpfswrap_query_trace();
 401         }
 402 }
 403
 404 static void copy_no_nl(char *out,
 405                        size_t out_size,
 406                        const char *in,
 407                        size_t in_len)
 408 {
 409         size_t len;
 410         /*
 411          * Some backends already add an extra newline, so also provide
 412          * a buffer without the newline character.
 413          */
 414         len = MIN(in_len, out_size - 1);
 415         if ((len > 0) && (in[len - 1] == '\n')) {
 416                 len--;
 417         }
 418
 419         memcpy(out, in, len);
 420         out[len] = '\0';
 421 }
 422
 423 static void debug_gpfs_log(int msg_level, const char *msg, size_t msg_len)
 424 {
 425         char no_nl[FORMAT_BUFR_SIZE];
 426
 427         if (state.hs_len > 0) {
 428                 copy_no_nl(no_nl,
 429                            sizeof(no_nl),
 430                            state.header_str,
 431                            state.hs_len);
 432                 gpfswrap_add_trace(msg_level, no_nl);
 433         }
 434
 435         copy_no_nl(no_nl, sizeof(no_nl), msg, msg_len);
 436         gpfswrap_add_trace(msg_level, no_nl);
 437 }
 438 #endif /* HAVE_GPFS */
 439
 440 #define DEBUG_RINGBUF_SIZE (1024 * 1024)
 441 #define DEBUG_RINGBUF_SIZE_OPT "size="
 442
 443 static char *debug_ringbuf;
 444 static size_t debug_ringbuf_size;
 445 static size_t debug_ringbuf_ofs;
 446
 447 /* We ensure in debug_ringbuf_log() that this is always \0 terminated */
 448 char *debug_get_ringbuf(void)
 449 {
 450         return debug_ringbuf;
 451 }
 452
 453 /* Return the size of the ringbuf (including a \0 terminator) */
 454 size_t debug_get_ringbuf_size(void)
 455 {
 456         return debug_ringbuf_size;
 457 }
 458
 459 static void debug_ringbuf_reload(bool enabled, bool previously_enabled,
 460                                  const char *prog_name, char *option)
 461 {
 462         bool cmp;
 463         size_t optlen = strlen(DEBUG_RINGBUF_SIZE_OPT);
 464
 465         debug_ringbuf_size = DEBUG_RINGBUF_SIZE;
 466         debug_ringbuf_ofs = 0;
 467
 468         SAFE_FREE(debug_ringbuf);
 469
 470         if (!enabled) {
 471                 return;
 472         }
 473
 474         if (option != NULL) {
 475                 cmp = strncmp(option, DEBUG_RINGBUF_SIZE_OPT, optlen);
 476                 if (cmp == 0) {
 477                         debug_ringbuf_size = (size_t)strtoull(
 478                                 option + optlen, NULL, 10);
 479                 }
 480         }
 481
 482         debug_ringbuf = calloc(debug_ringbuf_size, sizeof(char));
 483         if (debug_ringbuf == NULL) {
 484                 return;
 485         }
 486 }
 487
 488 static void _debug_ringbuf_log(int msg_level, const char *msg, size_t msg_len)
 489 {
 490         size_t allowed_size;
 491
 492         if (debug_ringbuf == NULL) {
 493                 return;
 494         }
 495
 496         /* Ensure the buffer is always \0 terminated */
 497         allowed_size = debug_ringbuf_size - 1;
 498
 499         if (msg_len > allowed_size) {
 500                 return;
 501         }
 502
 503         if ((debug_ringbuf_ofs + msg_len) < debug_ringbuf_ofs) {
 504                 return;
 505         }
 506
 507         if ((debug_ringbuf_ofs + msg_len) > allowed_size) {
 508                 debug_ringbuf_ofs = 0;
 509         }
 510
 511         memcpy(debug_ringbuf + debug_ringbuf_ofs, msg, msg_len);
 512         debug_ringbuf_ofs += msg_len;
 513 }
 514
 515 static void debug_ringbuf_log(int msg_level, const char *msg, size_t msg_len)
 516 {
 517         if (state.hs_len > 0) {
 518                 _debug_ringbuf_log(msg_level, state.header_str, state.hs_len);
 519         }
 520         _debug_ringbuf_log(msg_level, msg, msg_len);
 521 }
 522
 523 static struct debug_backend {
 524         const char *name;
 525         int log_level;
 526         int new_log_level;
 527         void (*reload)(bool enabled, bool prev_enabled,
 528                        const char *prog_name, char *option);
 529         void (*log)(int msg_level,
 530                     const char *msg,
 531                     size_t len);
 532         char *option;
 533 } debug_backends[] = {
 534         {
 535                 .name = "file",
 536                 .log = debug_file_log,
 537         },
 538 #ifdef WITH_SYSLOG
 539         {
 540                 .name = "syslog",
 541                 .reload = debug_syslog_reload,
 542                 .log = debug_syslog_log,
 543         },
 544 #endif
 545
 546 #if defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
 547         {
 548                 .name = "systemd",
 549                 .log = debug_systemd_log,
 550         },
 551 #endif
 552
 553 #ifdef HAVE_LTTNG_TRACEF
 554         {
 555                 .name = "lttng",
 556                 .log = debug_lttng_log,
 557         },
 558 #endif
 559
 560 #ifdef HAVE_GPFS
 561         {
 562                 .name = "gpfs",
 563                 .reload = debug_gpfs_reload,
 564                 .log = debug_gpfs_log,
 565         },
 566 #endif
 567         {
 568                 .name = "ringbuf",
 569                 .log = debug_ringbuf_log,
 570                 .reload = debug_ringbuf_reload,
 571         },
 572 };
 573
 574 static struct debug_backend *debug_find_backend(const char *name)
 575 {
 576         unsigned i;
 577
 578         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 579                 if (strcmp(name, debug_backends[i].name) == 0) {
 580                         return &debug_backends[i];
 581                 }
 582         }
 583
 584         return NULL;
 585 }
 586
 587 /*
 588  * parse "backend[:option][@loglevel]
 589  */
 590 static void debug_backend_parse_token(char *tok)
 591 {
 592         char *backend_name_option, *backend_name,*backend_level, *saveptr;
 593         char *backend_option;
 594         struct debug_backend *b;
 595
 596         /*
 597          * First parse into backend[:option] and loglevel
 598          */
 599         backend_name_option = strtok_r(tok, "@\0", &saveptr);
 600         if (backend_name_option == NULL) {
 601                 return;
 602         }
 603
 604         backend_level = strtok_r(NULL, "\0", &saveptr);
 605
 606         /*
 607          * Now parse backend[:option]
 608          */
 609         backend_name = strtok_r(backend_name_option, ":\0", &saveptr);
 610         if (backend_name == NULL) {
 611                 return;
 612         }
 613
 614         backend_option = strtok_r(NULL, "\0", &saveptr);
 615
 616         /*
 617          * Find and update backend
 618          */
 619         b = debug_find_backend(backend_name);
 620         if (b == NULL) {
 621                 return;
 622         }
 623
 624         if (backend_level == NULL) {
 625                 b->new_log_level = MAX_DEBUG_LEVEL;
 626         } else {
 627                 b->new_log_level = atoi(backend_level);
 628         }
 629
 630         if (backend_option != NULL) {
 631                 b->option = strdup(backend_option);
 632                 if (b->option == NULL) {
 633                         return;
 634                 }
 635         }
 636 }
 637
 638 /*
 639  * parse "backend1[:option1][@loglevel1] backend2[option2][@loglevel2] ... "
 640  * and enable/disable backends accordingly
 641  */
 642 static void debug_set_backends(const char *param)
 643 {
 644         size_t str_len = strlen(param);
 645         char str[str_len+1];
 646         char *tok, *saveptr;
 647         unsigned i;
 648
 649         /*
 650          * initialize new_log_level to detect backends that have been
 651          * disabled
 652          */
 653         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 654                 SAFE_FREE(debug_backends[i].option);
 655                 debug_backends[i].new_log_level = -1;
 656         }
 657
 658         memcpy(str, param, str_len + 1);
 659
 660         tok = strtok_r(str, LIST_SEP, &saveptr);
 661         if (tok == NULL) {
 662                 return;
 663         }
 664
 665         while (tok != NULL) {
 666                 debug_backend_parse_token(tok);
 667                 tok = strtok_r(NULL, LIST_SEP, &saveptr);
 668         }
 669
 670         /*
 671          * Let backends react to config changes
 672          */
 673         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 674                 struct debug_backend *b = &debug_backends[i];
 675
 676                 if (b->reload) {
 677                         bool enabled = b->new_log_level > -1;
 678                         bool previously_enabled = b->log_level > -1;
 679
 680                         b->reload(enabled, previously_enabled, state.prog_name,
 681                                   b->option);
 682                 }
 683                 b->log_level = b->new_log_level;
 684         }
 685 }
 686
 687 static void debug_backends_log(const char *msg, size_t msg_len, int msg_level)
 688 {
 689         size_t i;
 690
 691         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 692                 if (msg_level <= debug_backends[i].log_level) {
 693                         debug_backends[i].log(msg_level, msg, msg_len);
 694                 }
 695         }
 696
 697         /* Only log the header once */
 698         state.hs_len = 0;
 699 }
 700
 701 int debuglevel_get_class(size_t idx)
 702 {
 703         return dbgc_config[idx].loglevel;
 704 }
 705
 706 void debuglevel_set_class(size_t idx, int level)
 707 {
 708         dbgc_config[idx].loglevel = level;
 709 }
 710
 711
 712 /* -------------------------------------------------------------------------- **
 713  * Internal variables.
 714  *
 715  *  debug_count     - Number of debug messages that have been output.
 716  *                    Used to check log size.
 717  *
 718  *  current_msg_level    - Internal copy of the message debug level.  Written by
 719  *                    dbghdr() and read by Debug1().
 720  *
 721  *  format_bufr     - Used to format debug messages.  The dbgtext() function
 722  *                    prints debug messages to a string, and then passes the
 723  *                    string to format_debug_text(), which uses format_bufr
 724  *                    to build the formatted output.
 725  *
 726  *  format_pos      - Marks the first free byte of the format_bufr.
 727  *
 728  *
 729  *  log_overflow    - When this variable is true, never attempt to check the
 730  *                    size of the log. This is a hack, so that we can write
 731  *                    a message using DEBUG, from open_logs() when we
 732  *                    are unable to open a new log file for some reason.
 733  */
 734
 735 static int     debug_count    = 0;
 736 static char format_bufr[FORMAT_BUFR_SIZE];
 737 static size_t     format_pos     = 0;
 738 static bool    log_overflow   = false;
 739
 740 /*
 741  * Define all the debug class selection names here. Names *MUST NOT* contain
 742  * white space. There must be one name for each DBGC_<class name>, and they
 743  * must be in the table in the order of DBGC_<class name>..
 744  */
 745
 746 static char **classname_table = NULL;
 747
 748
 749 /* -------------------------------------------------------------------------- **
 750  * Functions...
 751  */
 752
 753 static void debug_init(void);
 754
 755 /***************************************************************************
 756  Free memory pointed to by global pointers.
 757 ****************************************************************************/
 758
 759 void gfree_debugsyms(void)
 760 {
 761         unsigned i;
 762
 763         TALLOC_FREE(classname_table);
 764
 765         if ( dbgc_config != debug_class_list_initial ) {
 766                 TALLOC_FREE( dbgc_config );
 767                 dbgc_config = discard_const_p(struct debug_class,
 768                                                    debug_class_list_initial);
 769         }
 770
 771         debug_num_classes = 0;
 772
 773         state.initialized = false;
 774
 775         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 776                 SAFE_FREE(debug_backends[i].option);
 777         }
 778 }
 779
 780 /****************************************************************************
 781 utility lists registered debug class names's
 782 ****************************************************************************/
 783
 784 char *debug_list_class_names_and_levels(void)
 785 {
 786         char *buf = talloc_strdup(NULL, "");
 787         size_t i;
 788         /* prepare strings */
 789         for (i = 0; i < debug_num_classes; i++) {
 790                 talloc_asprintf_addbuf(&buf,
 791                                        "%s:%d%s",
 792                                        classname_table[i],
 793                                        dbgc_config[i].loglevel,
 794                                        i == (debug_num_classes - 1) ? "\n" : " ");
 795         }
 796         return buf;
 797 }
 798
 799 /****************************************************************************
 800  Utility to translate names to debug class index's (internal version).
 801 ****************************************************************************/
 802
 803 static int debug_lookup_classname_int(const char* classname)
 804 {
 805         size_t i;
 806
 807         if (classname == NULL) {
 808                 return -1;
 809         }
 810
 811         for (i=0; i < debug_num_classes; i++) {
 812                 char *entry = classname_table[i];
 813                 if (entry != NULL && strcmp(classname, entry)==0) {
 814                         return i;
 815                 }
 816         }
 817         return -1;
 818 }
 819
 820 /****************************************************************************
 821  Add a new debug class to the system.
 822 ****************************************************************************/
 823
 824 int debug_add_class(const char *classname)
 825 {
 826         int ndx;
 827         struct debug_class *new_class_list = NULL;
 828         char **new_name_list;
 829         int default_level;
 830
 831         if (classname == NULL) {
 832                 return -1;
 833         }
 834
 835         /* check the init has yet been called */
 836         debug_init();
 837
 838         ndx = debug_lookup_classname_int(classname);
 839         if (ndx >= 0) {
 840                 return ndx;
 841         }
 842         ndx = debug_num_classes;
 843
 844         if (dbgc_config == debug_class_list_initial) {
 845                 /* Initial loading... */
 846                 new_class_list = NULL;
 847         } else {
 848                 new_class_list = dbgc_config;
 849         }
 850
 851         default_level = dbgc_config[DBGC_ALL].loglevel;
 852
 853         new_class_list = talloc_realloc(NULL,
 854                                         new_class_list,
 855                                         struct debug_class,
 856                                         ndx + 1);
 857         if (new_class_list == NULL) {
 858                 return -1;
 859         }
 860
 861         dbgc_config = new_class_list;
 862
 863         dbgc_config[ndx] = (struct debug_class) {
 864                 .loglevel = default_level,
 865                 .fd = -1,
 866         };
 867
 868         new_name_list = talloc_realloc(NULL, classname_table, char *, ndx + 1);
 869         if (new_name_list == NULL) {
 870                 return -1;
 871         }
 872         classname_table = new_name_list;
 873
 874         classname_table[ndx] = talloc_strdup(classname_table, classname);
 875         if (classname_table[ndx] == NULL) {
 876                 return -1;
 877         }
 878
 879         debug_num_classes = ndx + 1;
 880
 881         return ndx;
 882 }
 883
 884 /****************************************************************************
 885  Utility to translate names to debug class index's (public version).
 886 ****************************************************************************/
 887
 888 static int debug_lookup_classname(const char *classname)
 889 {
 890         int ndx;
 891
 892         if (classname == NULL || !*classname)
 893                 return -1;
 894
 895         ndx = debug_lookup_classname_int(classname);
 896
 897         if (ndx != -1)
 898                 return ndx;
 899
 900         DBG_WARNING("Unknown classname[%s] -> adding it...\n", classname);
 901         return debug_add_class(classname);
 902 }
 903
 904 /****************************************************************************
 905  Dump the current registered debug levels.
 906 ****************************************************************************/
 907
 908 static void debug_dump_status(int level)
 909 {
 910         size_t q;
 911
 912         DEBUG(level, ("INFO: Current debug levels:\n"));
 913         for (q = 0; q < debug_num_classes; q++) {
 914                 const char *classname = classname_table[q];
 915                 DEBUGADD(level, ("  %s: %d\n",
 916                                  classname,
 917                                  dbgc_config[q].loglevel));
 918         }
 919 }
 920
 921 static bool debug_parse_param(char *param)
 922 {
 923         char *class_name;
 924         char *class_file = NULL;
 925         char *class_level;
 926         char *saveptr = NULL;
 927         int ndx;
 928
 929         class_name = strtok_r(param, ":", &saveptr);
 930         if (class_name == NULL) {
 931                 return false;
 932         }
 933
 934         class_level = strtok_r(NULL, "@\0", &saveptr);
 935         if (class_level == NULL) {
 936                 return false;
 937         }
 938
 939         class_file = strtok_r(NULL, "\0", &saveptr);
 940
 941         ndx = debug_lookup_classname(class_name);
 942         if (ndx == -1) {
 943                 return false;
 944         }
 945
 946         dbgc_config[ndx].loglevel = atoi(class_level);
 947
 948         if (class_file == NULL) {
 949                 return true;
 950         }
 951
 952         TALLOC_FREE(dbgc_config[ndx].logfile);
 953
 954         dbgc_config[ndx].logfile = talloc_strdup(NULL, class_file);
 955         if (dbgc_config[ndx].logfile == NULL) {
 956                 return false;
 957         }
 958         return true;
 959 }
 960
 961 /****************************************************************************
 962  Parse the debug levels from smb.conf. Example debug level string:
 963   3 tdb:5 printdrivers:7
 964  Note: the 1st param has no "name:" preceding it.
 965 ****************************************************************************/
 966
 967 bool debug_parse_levels(const char *params_str)
 968 {
 969         size_t str_len = strlen(params_str);
 970         char str[str_len+1];
 971         char *tok, *saveptr;
 972         size_t i;
 973
 974         /* Just in case */
 975         debug_init();
 976
 977         memcpy(str, params_str, str_len+1);
 978
 979         tok = strtok_r(str, LIST_SEP, &saveptr);
 980         if (tok == NULL) {
 981                 return true;
 982         }
 983
 984         /* Allow DBGC_ALL to be specified w/o requiring its class name e.g."10"
 985          * v.s. "all:10", this is the traditional way to set DEBUGLEVEL
 986          */
 987         if (isdigit(tok[0])) {
 988                 dbgc_config[DBGC_ALL].loglevel = atoi(tok);
 989                 tok = strtok_r(NULL, LIST_SEP, &saveptr);
 990         } else {
 991                 dbgc_config[DBGC_ALL].loglevel = 0;
 992         }
 993
 994         /* Array is debug_num_classes long */
 995         for (i = DBGC_ALL+1; i < debug_num_classes; i++) {
 996                 dbgc_config[i].loglevel = dbgc_config[DBGC_ALL].loglevel;
 997                 TALLOC_FREE(dbgc_config[i].logfile);
 998         }
 999
1000         while (tok != NULL) {
1001                 bool ok;
1002
1003                 ok = debug_parse_param(tok);
1004                 if (!ok) {
1005                         DEBUG(0,("debug_parse_params: unrecognized debug "
1006                                  "class name or format [%s]\n", tok));
1007                         return false;
1008                 }
1009
1010                 tok = strtok_r(NULL, LIST_SEP, &saveptr);
1011         }
1012
1013         debug_dump_status(5);
1014
1015         return true;
1016 }
1017
1018 /* setup for logging of talloc warnings */
1019 static void talloc_log_fn(const char *msg)
1020 {
1021         DEBUG(0,("%s", msg));
1022 }
1023
1024 void debug_setup_talloc_log(void)
1025 {
1026         talloc_set_log_fn(talloc_log_fn);
1027 }
1028
1029
1030 /****************************************************************************
1031 Init debugging (one time stuff)
1032 ****************************************************************************/
1033
1034 static void debug_init(void)
1035 {
1036         size_t i;
1037
1038         if (state.initialized)
1039                 return;
1040
1041         state.initialized = true;
1042
1043         debug_setup_talloc_log();
1044
1045         for (i = 0; i < ARRAY_SIZE(default_classname_table); i++) {
1046                 debug_add_class(default_classname_table[i]);
1047         }
1048         dbgc_config[DBGC_ALL].fd = 2;
1049
1050         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
1051                 debug_backends[i].log_level = -1;
1052                 debug_backends[i].new_log_level = -1;
1053         }
1054 }
1055
1056 void debug_set_settings(struct debug_settings *settings,
1057                         const char *logging_param,
1058                         int syslog_level, bool syslog_only)
1059 {
1060         char fake_param[256];
1061         size_t len = 0;
1062
1063         /*
1064          * This forces in some smb.conf derived values into the debug
1065          * system. There are no pointers in this structure, so we can
1066          * just structure-assign it in
1067          */
1068         state.settings = *settings;
1069
1070         /*
1071          * If 'logging' is not set, create backend settings from
1072          * deprecated 'syslog' and 'syslog only' parameters
1073          */
1074         if (logging_param != NULL) {
1075                 len = strlen(logging_param);
1076         }
1077         if (len == 0) {
1078                 if (syslog_only) {
1079                         snprintf(fake_param, sizeof(fake_param),
1080                                  "syslog@%d", syslog_level - 1);
1081                 } else {
1082                         snprintf(fake_param, sizeof(fake_param),
1083                                  "syslog@%d file@%d", syslog_level -1,
1084                                  MAX_DEBUG_LEVEL);
1085                 }
1086
1087                 logging_param = fake_param;
1088         }
1089
1090         debug_set_backends(logging_param);
1091 }
1092
1093 static void ensure_hostname(void)
1094 {
1095         int ret;
1096
1097         if (state.hostname[0] != '\0') {
1098                 return;
1099         }
1100
1101         ret = gethostname(state.hostname, sizeof(state.hostname));
1102         if (ret != 0) {
1103                 strlcpy(state.hostname, "unknown", sizeof(state.hostname));
1104                 return;
1105         }
1106
1107         /*
1108          * Ensure NUL termination, since POSIX isn't clear about that.
1109          *
1110          * Don't worry about truncating at the first '.' or similar,
1111          * since this is usually not fully qualified.  Trying to
1112          * truncate opens up the multibyte character gates of hell.
1113          */
1114         state.hostname[sizeof(state.hostname) - 1] = '\0';
1115 }
1116
1117 void debug_set_hostname(const char *name)
1118 {
1119         strlcpy(state.hostname, name, sizeof(state.hostname));
1120 }
1121
1122 void debug_set_forced_log_priority(int forced_log_priority)
1123 {
1124         state.forced_log_priority = forced_log_priority;
1125 }
1126
1127 /**
1128  * Ensure debug logs are initialised.
1129  *
1130  * setup_logging() is called to direct logging to the correct outputs, whether
1131  * those be stderr, stdout, files, or syslog, and set the program name used in
1132  * the logs. It can be called multiple times.
1133  *
1134  * There is an order of precedence to the log type. Once set to DEBUG_FILE, it
1135  * cannot be reset DEFAULT_DEBUG_STDERR, but can be set to DEBUG_STDERR, after
1136  * which DEBUG_FILE is unavailable). This makes it possible to override for
1137  * debug to stderr on the command line, as the smb.conf cannot reset it back
1138  * to file-based logging. See enum debug_logtype.
1139  *
1140  * @param prog_name the program name. Directory path component will be
1141  *                  ignored.
1142  *
1143  * @param new_logtype the requested destination for the debug log,
1144  *                    as an enum debug_logtype.
1145  */
1146 void setup_logging(const char *prog_name, enum debug_logtype new_logtype)
1147 {
1148         debug_init();
1149         if (state.logtype < new_logtype) {
1150                 state.logtype = new_logtype;
1151         }
1152         if (prog_name) {
1153                 const char *p = strrchr(prog_name, '/');
1154
1155                 if (p) {
1156                         prog_name = p + 1;
1157                 }
1158
1159                 strlcpy(state.prog_name, prog_name, sizeof(state.prog_name));
1160         }
1161         reopen_logs_internal();
1162 }
1163
1164 /***************************************************************************
1165  Set the logfile name.
1166 **************************************************************************/
1167
1168 void debug_set_logfile(const char *name)
1169 {
1170         if (name == NULL || *name == 0) {
1171                 /* this copes with calls when smb.conf is not loaded yet */
1172                 return;
1173         }
1174         TALLOC_FREE(dbgc_config[DBGC_ALL].logfile);
1175         dbgc_config[DBGC_ALL].logfile = talloc_strdup(NULL, name);
1176
1177         reopen_logs_internal();
1178 }
1179
1180 static void debug_close_fd(int fd)
1181 {
1182         if (fd > 2) {
1183                 close(fd);
1184         }
1185 }
1186
1187 enum debug_logtype debug_get_log_type(void)
1188 {
1189         return state.logtype;
1190 }
1191
1192 bool debug_get_output_is_stderr(void)
1193 {
1194         return (state.logtype == DEBUG_DEFAULT_STDERR) || (state.logtype == DEBUG_STDERR);
1195 }
1196
1197 bool debug_get_output_is_stdout(void)
1198 {
1199         return (state.logtype == DEBUG_DEFAULT_STDOUT) || (state.logtype == DEBUG_STDOUT);
1200 }
1201
1202 void debug_set_callback(void *private_ptr, debug_callback_fn fn)
1203 {
1204         debug_init();
1205         if (fn) {
1206                 state.logtype = DEBUG_CALLBACK;
1207                 state.callback_private = private_ptr;
1208                 state.callback = fn;
1209         } else {
1210                 state.logtype = DEBUG_DEFAULT_STDERR;
1211                 state.callback_private = NULL;
1212                 state.callback = NULL;
1213         }
1214 }
1215
1216 static void debug_callback_log(const char *msg, size_t msg_len, int msg_level)
1217 {
1218         char msg_copy[msg_len];
1219
1220         if ((msg_len > 0) && (msg[msg_len-1] == '\n')) {
1221                 memcpy(msg_copy, msg, msg_len-1);
1222                 msg_copy[msg_len-1] = '\0';
1223                 msg = msg_copy;
1224         }
1225
1226         state.callback(state.callback_private, msg_level, msg);
1227 }
1228
1229 /**************************************************************************
1230  reopen the log files
1231  note that we now do this unconditionally
1232  We attempt to open the new debug fp before closing the old. This means
1233  if we run out of fd's we just keep using the old fd rather than aborting.
1234  Fix from dgibson@linuxcare.com.
1235 **************************************************************************/
1236
1237 static bool reopen_one_log(struct debug_class *config)
1238 {
1239         int old_fd = config->fd;
1240         const char *logfile = config->logfile;
1241         struct stat st;
1242         int new_fd;
1243         int ret;
1244
1245         if (logfile == NULL) {
1246                 debug_close_fd(old_fd);
1247                 config->fd = -1;
1248                 return true;
1249         }
1250
1251         new_fd = open(logfile, O_WRONLY|O_APPEND|O_CREAT, 0644);
1252         if (new_fd == -1) {
1253                 log_overflow = true;
1254                 DBG_ERR("Unable to open new log file '%s': %s\n",
1255                         logfile, strerror(errno));
1256                 log_overflow = false;
1257                 return false;
1258         }
1259
1260         debug_close_fd(old_fd);
1261         smb_set_close_on_exec(new_fd);
1262         config->fd = new_fd;
1263
1264         ret = fstat(new_fd, &st);
1265         if (ret != 0) {
1266                 log_overflow = true;
1267                 DBG_ERR("Unable to fstat() new log file '%s': %s\n",
1268                         logfile, strerror(errno));
1269                 log_overflow = false;
1270                 return false;
1271         }
1272
1273         config->ino = st.st_ino;
1274         return true;
1275 }
1276
1277 /**
1278   reopen the log file (usually called because the log file name might have changed)
1279 */
1280 bool reopen_logs_internal(void)
1281 {
1282         struct debug_backend *b = NULL;
1283         mode_t oldumask;
1284         size_t i;
1285         bool ok = true;
1286
1287         if (state.reopening_logs) {
1288                 return true;
1289         }
1290
1291         /* Now clear the SIGHUP induced flag */
1292         state.schedule_reopen_logs = false;
1293
1294         switch (state.logtype) {
1295         case DEBUG_CALLBACK:
1296                 return true;
1297         case DEBUG_STDOUT:
1298         case DEBUG_DEFAULT_STDOUT:
1299                 debug_close_fd(dbgc_config[DBGC_ALL].fd);
1300                 dbgc_config[DBGC_ALL].fd = 1;
1301                 return true;
1302
1303         case DEBUG_DEFAULT_STDERR:
1304         case DEBUG_STDERR:
1305                 debug_close_fd(dbgc_config[DBGC_ALL].fd);
1306                 dbgc_config[DBGC_ALL].fd = 2;
1307                 return true;
1308
1309         case DEBUG_FILE:
1310                 b = debug_find_backend("file");
1311                 assert(b != NULL);
1312
1313                 b->log_level = MAX_DEBUG_LEVEL;
1314                 break;
1315         }
1316
1317         oldumask = umask( 022 );
1318
1319         for (i = DBGC_ALL; i < debug_num_classes; i++) {
1320                 if (dbgc_config[i].logfile != NULL) {
1321                         break;
1322                 }
1323         }
1324         if (i == debug_num_classes) {
1325                 return false;
1326         }
1327
1328         state.reopening_logs = true;
1329
1330         for (i = DBGC_ALL; i < debug_num_classes; i++) {
1331                 ok = reopen_one_log(&dbgc_config[i]);
1332                 if (!ok) {
1333                         break;
1334                 }
1335         }
1336
1337         /* Fix from klausr@ITAP.Physik.Uni-Stuttgart.De
1338          * to fix problem where smbd's that generate less
1339          * than 100 messages keep growing the log.
1340          */
1341         force_check_log_size();
1342         (void)umask(oldumask);
1343
1344         /*
1345          * If log file was opened or created successfully, take over stderr to
1346          * catch output into logs.
1347          */
1348         if (!state.settings.debug_no_stderr_redirect &&
1349             dbgc_config[DBGC_ALL].fd > 0) {
1350                 if (dup2(dbgc_config[DBGC_ALL].fd, 2) == -1) {
1351                         /* Close stderr too, if dup2 can't point it -
1352                            at the logfile.  There really isn't much
1353                            that can be done on such a fundamental
1354                            failure... */
1355                         close_low_fd(2);
1356                 }
1357         }
1358
1359         state.reopening_logs = false;
1360
1361         return ok;
1362 }
1363
1364 /**************************************************************************
1365  Force a check of the log size.
1366  ***************************************************************************/
1367
1368 void force_check_log_size( void )
1369 {
1370         debug_count = 100;
1371 }
1372
1373 _PUBLIC_ void debug_schedule_reopen_logs(void)
1374 {
1375         state.schedule_reopen_logs = true;
1376 }
1377
1378
1379 /***************************************************************************
1380  Check to see if there is any need to check if the logfile has grown too big.
1381 **************************************************************************/
1382
1383 bool need_to_check_log_size(void)
1384 {
1385         int maxlog;
1386         size_t i;
1387
1388         if (debug_count < 100) {
1389                 return false;
1390         }
1391
1392         maxlog = state.settings.max_log_size * 1024;
1393         if (maxlog <= 0) {
1394                 debug_count = 0;
1395                 return false;
1396         }
1397
1398         if (dbgc_config[DBGC_ALL].fd > 2) {
1399                 return true;
1400         }
1401
1402         for (i = DBGC_ALL + 1; i < debug_num_classes; i++) {
1403                 if (dbgc_config[i].fd != -1) {
1404                         return true;
1405                 }
1406         }
1407
1408         debug_count = 0;
1409         return false;
1410 }
1411
1412 /**************************************************************************
1413  Check to see if the log has grown to be too big.
1414  **************************************************************************/
1415
1416 static void do_one_check_log_size(off_t maxlog, struct debug_class *config)
1417 {
1418         char name[strlen(config->logfile) + 5];
1419         struct stat st;
1420         int ret;
1421         bool reopen = false;
1422         bool ok;
1423
1424         if (maxlog == 0) {
1425                 return;
1426         }
1427
1428         ret = stat(config->logfile, &st);
1429         if (ret != 0) {
1430                 return;
1431         }
1432         if (st.st_size >= maxlog ) {
1433                 reopen = true;
1434         }
1435
1436         if (st.st_ino != config->ino) {
1437                 reopen = true;
1438         }
1439
1440         if (!reopen) {
1441                 return;
1442         }
1443
1444         /* reopen_logs_internal() modifies *_fd */
1445         (void)reopen_logs_internal();
1446
1447         if (config->fd <= 2) {
1448                 return;
1449         }
1450         ret = fstat(config->fd, &st);
1451         if (ret != 0) {
1452                 config->ino = (ino_t)0;
1453                 return;
1454         }
1455
1456         config->ino = st.st_ino;
1457
1458         if (st.st_size < maxlog) {
1459                 return;
1460         }
1461
1462         snprintf(name, sizeof(name), "%s.old", config->logfile);
1463
1464         (void)rename(config->logfile, name);
1465
1466         ok = reopen_logs_internal();
1467         if (ok) {
1468                 return;
1469         }
1470         /* We failed to reopen a log - continue using the old name. */
1471         (void)rename(name, config->logfile);
1472 }
1473
1474 static void do_check_log_size(off_t maxlog)
1475 {
1476         size_t i;
1477
1478         for (i = DBGC_ALL; i < debug_num_classes; i++) {
1479                 if (dbgc_config[i].fd == -1) {
1480                         continue;
1481                 }
1482                 if (dbgc_config[i].logfile == NULL) {
1483                         continue;
1484                 }
1485                 do_one_check_log_size(maxlog, &dbgc_config[i]);
1486         }
1487 }
1488
1489 void check_log_size( void )
1490 {
1491         off_t maxlog;
1492
1493         if (geteuid() != 0) {
1494                 /*
1495                  * We need to be root to change the log file (tests use a fake
1496                  * geteuid() from third_party/uid_wrapper). Otherwise we skip
1497                  * this and let the main smbd loop or some other process do
1498                  * the work.
1499                  */
1500                 return;
1501         }
1502
1503         if(log_overflow || (!state.schedule_reopen_logs && !need_to_check_log_size())) {
1504                 return;
1505         }
1506
1507         maxlog = state.settings.max_log_size * 1024;
1508
1509         if (state.schedule_reopen_logs) {
1510                 (void)reopen_logs_internal();
1511         }
1512
1513         do_check_log_size(maxlog);
1514
1515         /*
1516          * Here's where we need to panic if dbgc_config[DBGC_ALL].fd == 0 or -1
1517          * (invalid values)
1518          */
1519
1520         if (dbgc_config[DBGC_ALL].fd <= 0) {
1521                 /* This code should only be reached in very strange
1522                  * circumstances. If we merely fail to open the new log we
1523                  * should stick with the old one. ergo this should only be
1524                  * reached when opening the logs for the first time: at
1525                  * startup or when the log level is increased from zero.
1526                  * -dwg 6 June 2000
1527                  */
1528                 int fd = open( "/dev/console", O_WRONLY, 0);
1529                 if (fd != -1) {
1530                         smb_set_close_on_exec(fd);
1531                         dbgc_config[DBGC_ALL].fd = fd;
1532                         DBG_ERR("check_log_size: open of debug file %s failed "
1533                                 "- using console.\n",
1534                                 dbgc_config[DBGC_ALL].logfile);
1535                 } else {
1536                         /*
1537                          * We cannot continue without a debug file handle.
1538                          */
1539                         abort();
1540                 }
1541         }
1542         debug_count = 0;
1543 }
1544
1545 /*************************************************************************
1546  Write an debug message on the debugfile.
1547  This is called by format_debug_text().
1548 ************************************************************************/
1549
1550 static void Debug1(const char *msg, size_t msg_len)
1551 {
1552         int old_errno = errno;
1553
1554         debug_count++;
1555
1556         switch(state.logtype) {
1557         case DEBUG_CALLBACK:
1558                 debug_callback_log(msg, msg_len, current_msg_level);
1559                 break;
1560         case DEBUG_STDOUT:
1561         case DEBUG_STDERR:
1562         case DEBUG_DEFAULT_STDOUT:
1563         case DEBUG_DEFAULT_STDERR:
1564                 if (state.settings.debug_syslog_format ==
1565                     DEBUG_SYSLOG_FORMAT_ALWAYS) {
1566                         debug_file_log(current_msg_level, msg, msg_len);
1567                 } else {
1568                         if (dbgc_config[DBGC_ALL].fd > 0) {
1569                                 ssize_t ret;
1570                                 do {
1571                                         ret = write(dbgc_config[DBGC_ALL].fd,
1572                                                     msg,
1573                                                     msg_len);
1574                                 } while (ret == -1 && errno == EINTR);
1575                         }
1576                 }
1577                 break;
1578         case DEBUG_FILE:
1579                 debug_backends_log(msg, msg_len, current_msg_level);
1580                 break;
1581         };
1582
1583         errno = old_errno;
1584 }
1585
1586 /**************************************************************************
1587  Print the buffer content via Debug1(), then reset the buffer.
1588  Input:  none
1589  Output: none
1590 ****************************************************************************/
1591
1592 static void bufr_print( void )
1593 {
1594         format_bufr[format_pos] = '\0';
1595         (void)Debug1(format_bufr, format_pos);
1596         format_pos = 0;
1597 }
1598
1599 /*
1600  * If set (by tevent_thread_call_depth_set()) to value > 0, debug code will use
1601  * it for the trace indentation.
1602  */
1603 static size_t debug_call_depth = 0;
1604
1605 size_t *debug_call_depth_addr(void)
1606 {
1607         return &debug_call_depth;
1608 }
1609
1610 /***************************************************************************
1611  Format the debug message text.
1612
1613  Input:  msg - Text to be added to the "current" debug message text.
1614
1615  Output: none.
1616
1617  Notes:  The purpose of this is two-fold.  First, each call to syslog()
1618          (used by Debug1(), see above) generates a new line of syslog
1619          output.  This is fixed by storing the partial lines until the
1620          newline character is encountered.  Second, printing the debug
1621          message lines when a newline is encountered allows us to add
1622          spaces, thus indenting the body of the message and making it
1623          more readable.
1624 **************************************************************************/
1625
1626 static void format_debug_text( const char *msg )
1627 {
1628         size_t i;
1629         bool timestamp = (state.logtype == DEBUG_FILE && (state.settings.timestamp_logs));
1630
1631         debug_init();
1632
1633         for( i = 0; msg[i]; i++ ) {
1634                 /* Indent two spaces at each new line. */
1635                 if(timestamp && 0 == format_pos) {
1636                         /* Limit the maximum indentation to 20 levels */
1637                         size_t depth = MIN(20, debug_call_depth);
1638                         format_bufr[0] = format_bufr[1] = ' ';
1639                         format_pos = 2;
1640                         /*
1641                          * Indent by four spaces for each depth level,
1642                          * but only if the current debug level is >= 8.
1643                          */
1644                         if (depth > 0 && debuglevel_get() >= 8 &&
1645                             format_pos + 4 * depth < FORMAT_BUFR_SIZE) {
1646                                 memset(&format_bufr[format_pos],
1647                                        ' ',
1648                                        4 * depth);
1649                                 format_pos += 4 * depth;
1650                         }
1651                 }
1652
1653                 /* If there's room, copy the character to the format buffer. */
1654                 if (format_pos < FORMAT_BUFR_SIZE - 1)
1655                         format_bufr[format_pos++] = msg[i];
1656
1657                 /* If a newline is encountered, print & restart. */
1658                 if( '\n' == msg[i] )
1659                         bufr_print();
1660
1661                 /* If the buffer is full dump it out, reset it, and put out a line
1662                  * continuation indicator.
1663                  */
1664                 if (format_pos >= FORMAT_BUFR_SIZE - 1) {
1665                         const char cont[] = " +>\n";
1666                         bufr_print();
1667                         (void)Debug1(cont , sizeof(cont) - 1);
1668                 }
1669         }
1670
1671         /* Just to be safe... */
1672         format_bufr[format_pos] = '\0';
1673 }
1674
1675 /***************************************************************************
1676  Flush debug output, including the format buffer content.
1677
1678  Input:  none
1679  Output: none
1680 ***************************************************************************/
1681
1682 void dbgflush( void )
1683 {
1684         bufr_print();
1685 }
1686
1687 bool dbgsetclass(int level, int cls)
1688 {
1689         /* Set current_msg_level. */
1690         current_msg_level = level;
1691
1692         /* Set current message class */
1693         current_msg_class = cls;
1694
1695         return true;
1696 }
1697
1698 /***************************************************************************
1699  Put a Debug Header into header_str.
1700
1701  Input:  level    - Debug level of the message (not the system-wide debug
1702                     level. )
1703          cls      - Debuglevel class of the calling module.
1704          location - Pointer to a string containing the name of the file
1705                     from which this function was called, or an empty string
1706                     if the __FILE__ macro is not implemented.
1707          func     - Pointer to a string containing the name of the function
1708                     from which this function was called, or an empty string
1709                     if the __FUNCTION__ macro is not implemented.
1710
1711  Output: Always true.  This makes it easy to fudge a call to dbghdr()
1712          in a macro, since the function can be called as part of a test.
1713          Eg: ( (level <= DEBUGLEVEL) && (dbghdr(level,"",line)) )
1714
1715  Notes:  This function takes care of setting current_msg_level.
1716
1717 ****************************************************************************/
1718
1719 bool dbghdrclass(int level, int cls, const char *location, const char *func)
1720 {
1721         /* Ensure we don't lose any real errno value. */
1722         int old_errno = errno;
1723         bool verbose = false;
1724         struct timeval tv;
1725         struct timeval_buf tvbuf;
1726
1727         /*
1728          * This might be overkill, but if another early return is
1729          * added later then initialising these avoids potential
1730          * problems
1731          */
1732         state.hs_len = 0;
1733         state.header_str[0] = '\0';
1734
1735         if( format_pos ) {
1736                 /* This is a fudge.  If there is stuff sitting in the format_bufr, then
1737                  * the *right* thing to do is to call
1738                  *   format_debug_text( "\n" );
1739                  * to write the remainder, and then proceed with the new header.
1740                  * Unfortunately, there are several places in the code at which
1741                  * the DEBUG() macro is used to build partial lines.  That in mind,
1742                  * we'll work under the assumption that an incomplete line indicates
1743                  * that a new header is *not* desired.
1744                  */
1745                 return( true );
1746         }
1747
1748         dbgsetclass(level, cls);
1749
1750         /*
1751          * Don't print a header if we're logging to stdout,
1752          * unless 'debug syslog format = always'
1753          */
1754         if (state.logtype != DEBUG_FILE &&
1755             state.settings.debug_syslog_format != DEBUG_SYSLOG_FORMAT_ALWAYS)
1756         {
1757                 return true;
1758         }
1759
1760         /*
1761          * Print the header if timestamps (or debug syslog format) is
1762          * turned on.  If parameters are not yet loaded, then default
1763          * to timestamps on.
1764          */
1765         if (!(state.settings.timestamp_logs ||
1766               state.settings.debug_prefix_timestamp ||
1767               state.settings.debug_syslog_format != DEBUG_SYSLOG_FORMAT_NO))
1768         {
1769                 return true;
1770         }
1771
1772         GetTimeOfDay(&tv);
1773
1774         if (state.settings.debug_syslog_format != DEBUG_SYSLOG_FORMAT_NO) {
1775                 if (state.settings.debug_hires_timestamp) {
1776                         timeval_str_buf(&tv, true, true, &tvbuf);
1777                 } else {
1778                         time_t t;
1779                         struct tm *tm;
1780
1781                         t = (time_t)tv.tv_sec;
1782                         tm = localtime(&t);
1783                         if (tm != NULL) {
1784                                 size_t len;
1785                                 len = strftime(tvbuf.buf,
1786                                                sizeof(tvbuf.buf),
1787                                                "%b %e %T",
1788                                                tm);
1789                                 if (len == 0) {
1790                                         /* Trigger default time format below */
1791                                         tm = NULL;
1792                                 }
1793                         }
1794                         if (tm == NULL) {
1795                                 snprintf(tvbuf.buf,
1796                                          sizeof(tvbuf.buf),
1797                                          "%ld seconds since the Epoch", (long)t);
1798                         }
1799                 }
1800
1801                 ensure_hostname();
1802                 state.hs_len = snprintf(state.header_str,
1803                                         sizeof(state.header_str),
1804                                         "%s %.*s %s[%u]: ",
1805                                         tvbuf.buf,
1806                                         (int)(sizeof(state.hostname) - 1),
1807                                         state.hostname,
1808                                         state.prog_name,
1809                                         (unsigned int) getpid());
1810
1811                 goto full;
1812         }
1813
1814         timeval_str_buf(&tv, false, state.settings.debug_hires_timestamp,
1815                         &tvbuf);
1816
1817         state.hs_len = snprintf(state.header_str,
1818                                 sizeof(state.header_str),
1819                                 "[%s, %2d",
1820                                 tvbuf.buf,
1821                                 level);
1822         if (state.hs_len >= sizeof(state.header_str) - 1) {
1823                 goto full;
1824         }
1825
1826         if (unlikely(dbgc_config[cls].loglevel >= 10)) {
1827                 verbose = true;
1828         }
1829
1830         if (verbose || state.settings.debug_pid) {
1831                 state.hs_len += snprintf(state.header_str + state.hs_len,
1832                                          sizeof(state.header_str) - state.hs_len,
1833                                          ", pid=%u",
1834                                          (unsigned int)getpid());
1835                 if (state.hs_len >= sizeof(state.header_str) - 1) {
1836                         goto full;
1837                 }
1838         }
1839
1840         if (verbose || state.settings.debug_uid) {
1841                 state.hs_len += snprintf(state.header_str + state.hs_len,
1842                                          sizeof(state.header_str) - state.hs_len,
1843                                          ", effective(%u, %u), real(%u, %u)",
1844                                          (unsigned int)geteuid(),
1845                                          (unsigned int)getegid(),
1846                                          (unsigned int)getuid(),
1847                                          (unsigned int)getgid());
1848                 if (state.hs_len >= sizeof(state.header_str) - 1) {
1849                         goto full;
1850                 }
1851         }
1852
1853         if ((verbose || state.settings.debug_class)
1854             && (cls != DBGC_ALL)) {
1855                 state.hs_len += snprintf(state.header_str + state.hs_len,
1856                                          sizeof(state.header_str) - state.hs_len,
1857                                          ", class=%s",
1858                                          classname_table[cls]);
1859                 if (state.hs_len >= sizeof(state.header_str) - 1) {
1860                         goto full;
1861                 }
1862         }
1863
1864         if (debug_traceid_get() != 0) {
1865                 state.hs_len += snprintf(state.header_str + state.hs_len,
1866                                          sizeof(state.header_str) - state.hs_len,
1867                                          ", traceid=%" PRIu64,
1868                                          debug_traceid_get());
1869                 if (state.hs_len >= sizeof(state.header_str) - 1) {
1870                         goto full;
1871                 }
1872         }
1873
1874         if (debug_call_depth > 0) {
1875                 state.hs_len += snprintf(state.header_str + state.hs_len,
1876                                          sizeof(state.header_str) - state.hs_len,
1877                                          ", depth=%zu",
1878                                          debug_call_depth);
1879                 if (state.hs_len >= sizeof(state.header_str) - 1) {
1880                         goto full;
1881                 }
1882         }
1883
1884         state.header_str[state.hs_len] = ']';
1885         state.hs_len++;
1886         if (state.hs_len < sizeof(state.header_str) - 1) {
1887                 state.header_str[state.hs_len] = ' ';
1888                 state.hs_len++;
1889         }
1890         state.header_str[state.hs_len] = '\0';
1891
1892         if (!state.settings.debug_prefix_timestamp) {
1893                 state.hs_len += snprintf(state.header_str + state.hs_len,
1894                                          sizeof(state.header_str) - state.hs_len,
1895                                          "%s(%s)\n",
1896                                          location,
1897                                          func);
1898                 if (state.hs_len >= sizeof(state.header_str)) {
1899                         goto full;
1900                 }
1901         }
1902
1903 full:
1904         /*
1905          * Above code never overflows state.header_str and always
1906          * NUL-terminates correctly.  However, state.hs_len can point
1907          * past the end of the buffer to indicate that truncation
1908          * occurred, so fix it if necessary, since state.hs_len is
1909          * expected to be used after return.
1910          */
1911         if (state.hs_len >= sizeof(state.header_str)) {
1912                 state.hs_len = sizeof(state.header_str) - 1;
1913         }
1914
1915         errno = old_errno;
1916         return( true );
1917 }
1918
1919 /***************************************************************************
1920  Add text to the body of the "current" debug message via the format buffer.
1921
1922   Input:  format_str  - Format string, as used in printf(), et. al.
1923           ...         - Variable argument list.
1924
1925   ..or..  va_alist    - Old style variable parameter list starting point.
1926
1927   Output: Always true.  See dbghdr() for more info, though this is not
1928           likely to be used in the same way.
1929
1930 ***************************************************************************/
1931
1932 static inline bool __dbgtext_va(const char *format_str, va_list ap) PRINTF_ATTRIBUTE(1,0);
1933 static inline bool __dbgtext_va(const char *format_str, va_list ap)
1934 {
1935         char *msgbuf = NULL;
1936         bool ret = true;
1937         int res;
1938
1939         res = vasprintf(&msgbuf, format_str, ap);
1940         if (res != -1) {
1941                 format_debug_text(msgbuf);
1942         } else {
1943                 ret = false;
1944         }
1945         SAFE_FREE(msgbuf);
1946         return ret;
1947 }
1948
1949 bool dbgtext_va(const char *format_str, va_list ap)
1950 {
1951         return __dbgtext_va(format_str, ap);
1952 }
1953
1954 bool dbgtext(const char *format_str, ... )
1955 {
1956         va_list ap;
1957         bool ret;
1958
1959         va_start(ap, format_str);
1960         ret = __dbgtext_va(format_str, ap);
1961         va_end(ap);
1962
1963         return ret;
1964 }
1965
1966 static uint64_t debug_traceid = 0;
1967
1968 uint64_t debug_traceid_set(uint64_t id)
1969 {
1970         uint64_t old_id = debug_traceid;
1971         debug_traceid = id;
1972         return old_id;
1973 }
1974
1975 uint64_t debug_traceid_get(void)
1976 {
1977         return debug_traceid;
1978 }