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 "time_basic.h"
  28 #include "close_low_fd.h"
  29 #include "memory.h"
  30 #include "util_strlist.h" /* LIST_SEP */
  31 #include "blocking.h"
  32 #include "debug.h"
  33
  34 /* define what facility to use for syslog */
  35 #ifndef SYSLOG_FACILITY
  36 #define SYSLOG_FACILITY LOG_DAEMON
  37 #endif
  38
  39 /* -------------------------------------------------------------------------- **
  40  * Defines...
  41  */
  42
  43 /*
  44  * format_bufr[FORMAT_BUFR_SIZE - 1] should always be reserved
  45  * for a terminating null byte.
  46  */
  47 #define FORMAT_BUFR_SIZE 1024
  48
  49 /* -------------------------------------------------------------------------- **
  50  * This module implements Samba's debugging utility.
  51  *
  52  * The syntax of a debugging log file is represented as:
  53  *
  54  *  <debugfile> :== { <debugmsg> }
  55  *
  56  *  <debugmsg>  :== <debughdr> '\n' <debugtext>
  57  *
  58  *  <debughdr>  :== '[' TIME ',' LEVEL ']' [ [FILENAME ':'] [FUNCTION '()'] ]
  59  *
  60  *  <debugtext> :== { <debugline> }
  61  *
  62  *  <debugline> :== TEXT '\n'
  63  *
  64  * TEXT     is a string of characters excluding the newline character.
  65  * LEVEL    is the DEBUG level of the message (an integer in the range 0..10).
  66  * TIME     is a timestamp.
  67  * FILENAME is the name of the file from which the debug message was generated.
  68  * FUNCTION is the function from which the debug message was generated.
  69  *
  70  * Basically, what that all means is:
  71  *
  72  * - A debugging log file is made up of debug messages.
  73  *
  74  * - Each debug message is made up of a header and text.  The header is
  75  *   separated from the text by a newline.
  76  *
  77  * - The header begins with the timestamp and debug level of the message
  78  *   enclosed in brackets.  The filename and function from which the
  79  *   message was generated may follow.  The filename is terminated by a
  80  *   colon, and the function name is terminated by parenthesis.
  81  *
  82  * - The message text is made up of zero or more lines, each terminated by
  83  *   a newline.
  84  */
  85
  86 /* state variables for the debug system */
  87 static struct {
  88         bool initialized;
  89         int fd;   /* The log file handle */
  90         enum debug_logtype logtype; /* The type of logging we are doing: eg stdout, file, stderr */
  91         const char *prog_name;
  92         bool reopening_logs;
  93         bool schedule_reopen_logs;
  94
  95         struct debug_settings settings;
  96         char *debugf;
  97         debug_callback_fn callback;
  98         void *callback_private;
  99 } state = {
 100         .settings = {
 101                 .timestamp_logs = true
 102         },
 103         .fd = 2 /* stderr by default */
 104 };
 105
 106 #if defined(WITH_SYSLOG) || defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
 107 static int debug_level_to_priority(int level)
 108 {
 109         /*
 110          * map debug levels to syslog() priorities
 111          */
 112         static const int priority_map[] = {
 113                 LOG_ERR,     /* 0 */
 114                 LOG_WARNING, /* 1 */
 115                 LOG_NOTICE,  /* 2 */
 116                 LOG_NOTICE,  /* 3 */
 117                 LOG_NOTICE,  /* 4 */
 118                 LOG_NOTICE,  /* 5 */
 119                 LOG_INFO,    /* 6 */
 120                 LOG_INFO,    /* 7 */
 121                 LOG_INFO,    /* 8 */
 122                 LOG_INFO,    /* 9 */
 123         };
 124         int priority;
 125
 126         if( level >= ARRAY_SIZE(priority_map) || level < 0)
 127                 priority = LOG_DEBUG;
 128         else
 129                 priority = priority_map[level];
 130
 131         return priority;
 132 }
 133 #endif
 134
 135 /* -------------------------------------------------------------------------- **
 136  * Debug backends. When logging to DEBUG_FILE, send the log entries to
 137  * all active backends.
 138  */
 139
 140 static void debug_file_log(int msg_level,
 141                            const char *msg, const char *msg_no_nl)
 142 {
 143         ssize_t ret;
 144
 145         check_log_size();
 146         do {
 147                 ret = write(state.fd, msg, strlen(msg));
 148         } while (ret == -1 && errno == EINTR);
 149 }
 150
 151 #ifdef WITH_SYSLOG
 152 static void debug_syslog_reload(bool enabled, bool previously_enabled,
 153                                 const char *prog_name, char *option)
 154 {
 155         if (enabled && !previously_enabled) {
 156 #ifdef LOG_DAEMON
 157                 openlog(prog_name, LOG_PID, SYSLOG_FACILITY);
 158 #else
 159                 /* for old systems that have no facility codes. */
 160                 openlog(prog_name, LOG_PID );
 161 #endif
 162                 return;
 163         }
 164
 165         if (!enabled && previously_enabled) {
 166                 closelog();
 167         }
 168 }
 169
 170 static void debug_syslog_log(int msg_level,
 171                              const char *msg, const char *msg_no_nl)
 172 {
 173         int priority;
 174
 175         priority = debug_level_to_priority(msg_level);
 176
 177         /*
 178          * Specify the facility to interoperate with other syslog
 179          * callers (vfs_full_audit for example).
 180          */
 181         priority |= SYSLOG_FACILITY;
 182
 183         syslog(priority, "%s", msg);
 184 }
 185 #endif /* WITH_SYSLOG */
 186
 187 #if defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
 188 #include <systemd/sd-journal.h>
 189 static void debug_systemd_log(int msg_level,
 190                               const char *msg, const char *msg_no_nl)
 191 {
 192         sd_journal_send("MESSAGE=%s", msg_no_nl,
 193                         "PRIORITY=%d", debug_level_to_priority(msg_level),
 194                         "LEVEL=%d", msg_level,
 195                         NULL);
 196 }
 197 #endif
 198
 199 #ifdef HAVE_LTTNG_TRACEF
 200 #include <lttng/tracef.h>
 201 static void debug_lttng_log(int msg_level,
 202                             const char *msg, const char *msg_no_nl)
 203 {
 204         tracef(msg_no_nl);
 205 }
 206 #endif /* WITH_LTTNG_TRACEF */
 207
 208 #ifdef HAVE_GPFS
 209 #include "gpfswrap.h"
 210 static void debug_gpfs_reload(bool enabled, bool previously_enabled,
 211                               const char *prog_name, char *option)
 212 {
 213         gpfswrap_init();
 214
 215         if (enabled && !previously_enabled) {
 216                 gpfswrap_init_trace();
 217                 return;
 218         }
 219
 220         if (!enabled && previously_enabled) {
 221                 gpfswrap_fini_trace();
 222                 return;
 223         }
 224
 225         if (enabled) {
 226                 /*
 227                  * Trigger GPFS library to adjust state if necessary.
 228                  */
 229                 gpfswrap_query_trace();
 230         }
 231 }
 232
 233 static void debug_gpfs_log(int msg_level,
 234                            const char *msg, const char *msg_no_nl)
 235 {
 236         gpfswrap_add_trace(msg_level, msg_no_nl);
 237 }
 238 #endif /* HAVE_GPFS */
 239
 240 #define DEBUG_RINGBUF_SIZE (1024 * 1024)
 241 #define DEBUG_RINGBUF_SIZE_OPT "size="
 242
 243 static char *debug_ringbuf;
 244 static size_t debug_ringbuf_size;
 245 static size_t debug_ringbuf_ofs;
 246
 247 /* We ensure in debug_ringbuf_log() that this is always \0 terminated */
 248 char *debug_get_ringbuf(void)
 249 {
 250         return debug_ringbuf;
 251 }
 252
 253 /* Return the size of the ringbuf (including a \0 terminator) */
 254 size_t debug_get_ringbuf_size(void)
 255 {
 256         return debug_ringbuf_size;
 257 }
 258
 259 static void debug_ringbuf_reload(bool enabled, bool previously_enabled,
 260                                  const char *prog_name, char *option)
 261 {
 262         bool cmp;
 263         size_t optlen = strlen(DEBUG_RINGBUF_SIZE_OPT);
 264
 265         debug_ringbuf_size = DEBUG_RINGBUF_SIZE;
 266         debug_ringbuf_ofs = 0;
 267
 268         SAFE_FREE(debug_ringbuf);
 269
 270         if (!enabled) {
 271                 return;
 272         }
 273
 274         if (option != NULL) {
 275                 cmp = strncmp(option, DEBUG_RINGBUF_SIZE_OPT, optlen);
 276                 if (cmp == 0) {
 277                         debug_ringbuf_size = (size_t)strtoull(
 278                                 option + optlen, NULL, 10);
 279                 }
 280         }
 281
 282         debug_ringbuf = calloc(debug_ringbuf_size, sizeof(char));
 283         if (debug_ringbuf == NULL) {
 284                 return;
 285         }
 286 }
 287
 288 static void debug_ringbuf_log(int msg_level,
 289                               const char *msg,
 290                               const char *msg_no_nl)
 291 {
 292         size_t msglen = strlen(msg);
 293         size_t allowed_size;
 294
 295         if (debug_ringbuf == NULL) {
 296                 return;
 297         }
 298
 299         /* Ensure the buffer is always \0 terminated */
 300         allowed_size = debug_ringbuf_size - 1;
 301
 302         if (msglen > allowed_size) {
 303                 return;
 304         }
 305
 306         if ((debug_ringbuf_ofs + msglen) < debug_ringbuf_ofs) {
 307                 return;
 308         }
 309
 310         if ((debug_ringbuf_ofs + msglen) > allowed_size) {
 311                 debug_ringbuf_ofs = 0;
 312         }
 313
 314         memcpy(debug_ringbuf + debug_ringbuf_ofs, msg, msglen);
 315         debug_ringbuf_ofs += msglen;
 316 }
 317
 318 static struct debug_backend {
 319         const char *name;
 320         int log_level;
 321         int new_log_level;
 322         void (*reload)(bool enabled, bool prev_enabled,
 323                        const char *prog_name, char *option);
 324         void (*log)(int msg_level, const char *msg, const char *msg_no_nl);
 325         char *option;
 326 } debug_backends[] = {
 327         {
 328                 .name = "file",
 329                 .log = debug_file_log,
 330         },
 331 #ifdef WITH_SYSLOG
 332         {
 333                 .name = "syslog",
 334                 .reload = debug_syslog_reload,
 335                 .log = debug_syslog_log,
 336         },
 337 #endif
 338
 339 #if defined(HAVE_LIBSYSTEMD_JOURNAL) || defined(HAVE_LIBSYSTEMD)
 340         {
 341                 .name = "systemd",
 342                 .log = debug_systemd_log,
 343         },
 344 #endif
 345
 346 #ifdef HAVE_LTTNG_TRACEF
 347         {
 348                 .name = "lttng",
 349                 .log = debug_lttng_log,
 350         },
 351 #endif
 352
 353 #ifdef HAVE_GPFS
 354         {
 355                 .name = "gpfs",
 356                 .reload = debug_gpfs_reload,
 357                 .log = debug_gpfs_log,
 358         },
 359 #endif
 360         {
 361                 .name = "ringbuf",
 362                 .log = debug_ringbuf_log,
 363                 .reload = debug_ringbuf_reload,
 364         },
 365 };
 366
 367 static struct debug_backend *debug_find_backend(const char *name)
 368 {
 369         unsigned i;
 370
 371         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 372                 if (strcmp(name, debug_backends[i].name) == 0) {
 373                         return &debug_backends[i];
 374                 }
 375         }
 376
 377         return NULL;
 378 }
 379
 380 /*
 381  * parse "backend[:option][@loglevel]
 382  */
 383 static void debug_backend_parse_token(char *tok)
 384 {
 385         char *backend_name_option, *backend_name,*backend_level, *saveptr;
 386         char *backend_option;
 387         struct debug_backend *b;
 388
 389         /*
 390          * First parse into backend[:option] and loglevel
 391          */
 392         backend_name_option = strtok_r(tok, "@\0", &saveptr);
 393         if (backend_name_option == NULL) {
 394                 return;
 395         }
 396
 397         backend_level = strtok_r(NULL, "\0", &saveptr);
 398
 399         /*
 400          * Now parse backend[:option]
 401          */
 402         backend_name = strtok_r(backend_name_option, ":\0", &saveptr);
 403         if (backend_name == NULL) {
 404                 return;
 405         }
 406
 407         backend_option = strtok_r(NULL, "\0", &saveptr);
 408
 409         /*
 410          * Find and update backend
 411          */
 412         b = debug_find_backend(backend_name);
 413         if (b == NULL) {
 414                 return;
 415         }
 416
 417         if (backend_level == NULL) {
 418                 b->new_log_level = MAX_DEBUG_LEVEL;
 419         } else {
 420                 b->new_log_level = atoi(backend_level);
 421         }
 422
 423         if (backend_option != NULL) {
 424                 b->option = strdup(backend_option);
 425                 if (b->option == NULL) {
 426                         return;
 427                 }
 428         }
 429 }
 430
 431 /*
 432  * parse "backend1[:option1][@loglevel1] backend2[option2][@loglevel2] ... "
 433  * and enable/disable backends accordingly
 434  */
 435 static void debug_set_backends(const char *param)
 436 {
 437         size_t str_len = strlen(param);
 438         char str[str_len+1];
 439         char *tok, *saveptr;
 440         unsigned i;
 441
 442         /*
 443          * initialize new_log_level to detect backends that have been
 444          * disabled
 445          */
 446         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 447                 SAFE_FREE(debug_backends[i].option);
 448                 debug_backends[i].new_log_level = -1;
 449         }
 450
 451         memcpy(str, param, str_len + 1);
 452
 453         tok = strtok_r(str, LIST_SEP, &saveptr);
 454         if (tok == NULL) {
 455                 return;
 456         }
 457
 458         while (tok != NULL) {
 459                 debug_backend_parse_token(tok);
 460                 tok = strtok_r(NULL, LIST_SEP, &saveptr);
 461         }
 462
 463         /*
 464          * Let backends react to config changes
 465          */
 466         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 467                 struct debug_backend *b = &debug_backends[i];
 468
 469                 if (b->reload) {
 470                         bool enabled = b->new_log_level > -1;
 471                         bool previously_enabled = b->log_level > -1;
 472
 473                         b->reload(enabled, previously_enabled, state.prog_name,
 474                                   b->option);
 475                 }
 476                 b->log_level = b->new_log_level;
 477         }
 478 }
 479
 480 static void debug_backends_log(const char *msg, int msg_level)
 481 {
 482         char msg_no_nl[FORMAT_BUFR_SIZE];
 483         unsigned i;
 484         int len;
 485
 486         /*
 487          * Some backends already add an extra newline, so also provide
 488          * a buffer without the newline character.
 489          */
 490         len = MIN(strlen(msg), FORMAT_BUFR_SIZE - 1);
 491         if ((len > 0) && (msg[len - 1] == '\n')) {
 492                 len--;
 493         }
 494
 495         memcpy(msg_no_nl, msg, len);
 496         msg_no_nl[len] = '\0';
 497
 498         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 499                 if (msg_level <= debug_backends[i].log_level) {
 500                         debug_backends[i].log(msg_level, msg, msg_no_nl);
 501                 }
 502         }
 503 }
 504
 505 /* -------------------------------------------------------------------------- **
 506  * External variables.
 507  */
 508
 509 /*
 510    used to check if the user specified a
 511    logfile on the command line
 512 */
 513 bool    override_logfile;
 514
 515 static const char *default_classname_table[] = {
 516         [DBGC_ALL] =            "all",
 517         [DBGC_TDB] =            "tdb",
 518         [DBGC_PRINTDRIVERS] =   "printdrivers",
 519         [DBGC_LANMAN] =         "lanman",
 520         [DBGC_SMB] =            "smb",
 521         [DBGC_RPC_PARSE] =      "rpc_parse",
 522         [DBGC_RPC_SRV] =        "rpc_srv",
 523         [DBGC_RPC_CLI] =        "rpc_cli",
 524         [DBGC_PASSDB] =         "passdb",
 525         [DBGC_SAM] =            "sam",
 526         [DBGC_AUTH] =           "auth",
 527         [DBGC_WINBIND] =        "winbind",
 528         [DBGC_VFS] =            "vfs",
 529         [DBGC_IDMAP] =          "idmap",
 530         [DBGC_QUOTA] =          "quota",
 531         [DBGC_ACLS] =           "acls",
 532         [DBGC_LOCKING] =        "locking",
 533         [DBGC_MSDFS] =          "msdfs",
 534         [DBGC_DMAPI] =          "dmapi",
 535         [DBGC_REGISTRY] =       "registry",
 536         [DBGC_SCAVENGER] =      "scavenger",
 537         [DBGC_DNS] =            "dns",
 538         [DBGC_LDB] =            "ldb",
 539         [DBGC_TEVENT] =         "tevent",
 540         [DBGC_AUTH_AUDIT] =     "auth_audit",
 541         [DBGC_AUTH_AUDIT_JSON] = "auth_json_audit",
 542         [DBGC_KERBEROS] =       "kerberos",
 543         [DBGC_DRS_REPL] =       "drs_repl",
 544         [DBGC_SMB2] =           "smb2",
 545         [DBGC_SMB2_CREDITS] =   "smb2_credits",
 546         [DBGC_DSDB_AUDIT]  =    "dsdb_audit",
 547         [DBGC_DSDB_AUDIT_JSON] = "dsdb_json_audit",
 548         [DBGC_DSDB_PWD_AUDIT]  =        "dsdb_password_audit",
 549         [DBGC_DSDB_PWD_AUDIT_JSON] = "dsdb_password_json_audit",
 550         [DBGC_DSDB_TXN_AUDIT]  =        "dsdb_transaction_audit",
 551         [DBGC_DSDB_TXN_AUDIT_JSON] = "dsdb_transaction_json_audit",
 552 };
 553
 554 /*
 555  * This is to allow reading of DEBUGLEVEL_CLASS before the debug
 556  * system has been initialized.
 557  */
 558 static const int debug_class_list_initial[ARRAY_SIZE(default_classname_table)];
 559
 560 static int debug_num_classes = 0;
 561 int     *DEBUGLEVEL_CLASS = discard_const_p(int, debug_class_list_initial);
 562
 563
 564 /* -------------------------------------------------------------------------- **
 565  * Internal variables.
 566  *
 567  *  debug_count     - Number of debug messages that have been output.
 568  *                    Used to check log size.
 569  *
 570  *  current_msg_level    - Internal copy of the message debug level.  Written by
 571  *                    dbghdr() and read by Debug1().
 572  *
 573  *  format_bufr     - Used to format debug messages.  The dbgtext() function
 574  *                    prints debug messages to a string, and then passes the
 575  *                    string to format_debug_text(), which uses format_bufr
 576  *                    to build the formatted output.
 577  *
 578  *  format_pos      - Marks the first free byte of the format_bufr.
 579  *
 580  *
 581  *  log_overflow    - When this variable is true, never attempt to check the
 582  *                    size of the log. This is a hack, so that we can write
 583  *                    a message using DEBUG, from open_logs() when we
 584  *                    are unable to open a new log file for some reason.
 585  */
 586
 587 static int     debug_count    = 0;
 588 static int     current_msg_level   = 0;
 589 static char format_bufr[FORMAT_BUFR_SIZE];
 590 static size_t     format_pos     = 0;
 591 static bool    log_overflow   = false;
 592
 593 /*
 594  * Define all the debug class selection names here. Names *MUST NOT* contain
 595  * white space. There must be one name for each DBGC_<class name>, and they
 596  * must be in the table in the order of DBGC_<class name>..
 597  */
 598
 599 static char **classname_table = NULL;
 600
 601
 602 /* -------------------------------------------------------------------------- **
 603  * Functions...
 604  */
 605
 606 static void debug_init(void);
 607
 608 /***************************************************************************
 609  Free memory pointed to by global pointers.
 610 ****************************************************************************/
 611
 612 void gfree_debugsyms(void)
 613 {
 614         unsigned i;
 615
 616         TALLOC_FREE(classname_table);
 617
 618         if ( DEBUGLEVEL_CLASS != debug_class_list_initial ) {
 619                 TALLOC_FREE( DEBUGLEVEL_CLASS );
 620                 DEBUGLEVEL_CLASS = discard_const_p(int, debug_class_list_initial);
 621         }
 622
 623         debug_num_classes = 0;
 624
 625         state.initialized = false;
 626
 627         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 628                 SAFE_FREE(debug_backends[i].option);
 629         }
 630 }
 631
 632 /****************************************************************************
 633 utility lists registered debug class names's
 634 ****************************************************************************/
 635
 636 char *debug_list_class_names_and_levels(void)
 637 {
 638         char *buf = NULL;
 639         int i;
 640         /* prepare strings */
 641         for (i = 0; i < debug_num_classes; i++) {
 642                 buf = talloc_asprintf_append(buf,
 643                                              "%s:%d%s",
 644                                              classname_table[i],
 645                                              DEBUGLEVEL_CLASS[i],
 646                                              i == (debug_num_classes - 1) ? "\n" : " ");
 647                 if (buf == NULL) {
 648                         return NULL;
 649                 }
 650         }
 651         return buf;
 652 }
 653
 654 /****************************************************************************
 655  Utility to translate names to debug class index's (internal version).
 656 ****************************************************************************/
 657
 658 static int debug_lookup_classname_int(const char* classname)
 659 {
 660         int i;
 661
 662         if (!classname) return -1;
 663
 664         for (i=0; i < debug_num_classes; i++) {
 665                 if (strcmp(classname, classname_table[i])==0)
 666                         return i;
 667         }
 668         return -1;
 669 }
 670
 671 /****************************************************************************
 672  Add a new debug class to the system.
 673 ****************************************************************************/
 674
 675 int debug_add_class(const char *classname)
 676 {
 677         int ndx;
 678         int *new_class_list;
 679         char **new_name_list;
 680         int default_level;
 681
 682         if (!classname)
 683                 return -1;
 684
 685         /* check the init has yet been called */
 686         debug_init();
 687
 688         ndx = debug_lookup_classname_int(classname);
 689         if (ndx >= 0)
 690                 return ndx;
 691         ndx = debug_num_classes;
 692
 693         if (DEBUGLEVEL_CLASS == debug_class_list_initial) {
 694                 /* Initial loading... */
 695                 new_class_list = NULL;
 696         } else {
 697                 new_class_list = DEBUGLEVEL_CLASS;
 698         }
 699
 700         default_level = DEBUGLEVEL_CLASS[DBGC_ALL];
 701
 702         new_class_list = talloc_realloc(NULL, new_class_list, int, ndx + 1);
 703         if (!new_class_list)
 704                 return -1;
 705         DEBUGLEVEL_CLASS = new_class_list;
 706
 707         DEBUGLEVEL_CLASS[ndx] = default_level;
 708
 709         new_name_list = talloc_realloc(NULL, classname_table, char *, ndx + 1);
 710         if (!new_name_list)
 711                 return -1;
 712         classname_table = new_name_list;
 713
 714         classname_table[ndx] = talloc_strdup(classname_table, classname);
 715         if (! classname_table[ndx])
 716                 return -1;
 717
 718         debug_num_classes = ndx + 1;
 719
 720         return ndx;
 721 }
 722
 723 /****************************************************************************
 724  Utility to translate names to debug class index's (public version).
 725 ****************************************************************************/
 726
 727 static int debug_lookup_classname(const char *classname)
 728 {
 729         int ndx;
 730
 731         if (!classname || !*classname)
 732                 return -1;
 733
 734         ndx = debug_lookup_classname_int(classname);
 735
 736         if (ndx != -1)
 737                 return ndx;
 738
 739         DEBUG(0, ("debug_lookup_classname(%s): Unknown class\n",
 740                   classname));
 741         return debug_add_class(classname);
 742 }
 743
 744 /****************************************************************************
 745  Dump the current registered debug levels.
 746 ****************************************************************************/
 747
 748 static void debug_dump_status(int level)
 749 {
 750         int q;
 751
 752         DEBUG(level, ("INFO: Current debug levels:\n"));
 753         for (q = 0; q < debug_num_classes; q++) {
 754                 const char *classname = classname_table[q];
 755                 DEBUGADD(level, ("  %s: %d\n",
 756                                  classname,
 757                                  DEBUGLEVEL_CLASS[q]));
 758         }
 759 }
 760
 761 static bool debug_parse_param(char *param)
 762 {
 763         char *class_name;
 764         char *class_level;
 765         char *saveptr = NULL;
 766         int ndx;
 767
 768         class_name = strtok_r(param, ":", &saveptr);
 769         if (class_name == NULL) {
 770                 return false;
 771         }
 772
 773         class_level = strtok_r(NULL, "\0", &saveptr);
 774         if (class_level == NULL) {
 775                 return false;
 776         }
 777
 778         ndx = debug_lookup_classname(class_name);
 779         if (ndx == -1) {
 780                 return false;
 781         }
 782
 783         DEBUGLEVEL_CLASS[ndx] = atoi(class_level);
 784
 785         return true;
 786 }
 787
 788 /****************************************************************************
 789  Parse the debug levels from smb.conf. Example debug level string:
 790   3 tdb:5 printdrivers:7
 791  Note: the 1st param has no "name:" preceeding it.
 792 ****************************************************************************/
 793
 794 bool debug_parse_levels(const char *params_str)
 795 {
 796         size_t str_len = strlen(params_str);
 797         char str[str_len+1];
 798         char *tok, *saveptr;
 799         int i;
 800
 801         /* Just in case */
 802         debug_init();
 803
 804         memcpy(str, params_str, str_len+1);
 805
 806         tok = strtok_r(str, LIST_SEP, &saveptr);
 807         if (tok == NULL) {
 808                 return true;
 809         }
 810
 811         /* Allow DBGC_ALL to be specified w/o requiring its class name e.g."10"
 812          * v.s. "all:10", this is the traditional way to set DEBUGLEVEL
 813          */
 814         if (isdigit(tok[0])) {
 815                 DEBUGLEVEL_CLASS[DBGC_ALL] = atoi(tok);
 816                 tok = strtok_r(NULL, LIST_SEP, &saveptr);
 817         } else {
 818                 DEBUGLEVEL_CLASS[DBGC_ALL] = 0;
 819         }
 820
 821         /* Array is debug_num_classes long */
 822         for (i = DBGC_ALL+1; i < debug_num_classes; i++) {
 823                 DEBUGLEVEL_CLASS[i] = DEBUGLEVEL_CLASS[DBGC_ALL];
 824         }
 825
 826         while (tok != NULL) {
 827                 bool ok;
 828
 829                 ok = debug_parse_param(tok);
 830                 if (!ok) {
 831                         DEBUG(0,("debug_parse_params: unrecognized debug "
 832                                  "class name or format [%s]\n", tok));
 833                         return false;
 834                 }
 835
 836                 tok = strtok_r(NULL, LIST_SEP, &saveptr);
 837         }
 838
 839         debug_dump_status(5);
 840
 841         return true;
 842 }
 843
 844 /* setup for logging of talloc warnings */
 845 static void talloc_log_fn(const char *msg)
 846 {
 847         DEBUG(0,("%s", msg));
 848 }
 849
 850 void debug_setup_talloc_log(void)
 851 {
 852         talloc_set_log_fn(talloc_log_fn);
 853 }
 854
 855
 856 /****************************************************************************
 857 Init debugging (one time stuff)
 858 ****************************************************************************/
 859
 860 static void debug_init(void)
 861 {
 862         size_t i;
 863
 864         if (state.initialized)
 865                 return;
 866
 867         state.initialized = true;
 868
 869         debug_setup_talloc_log();
 870
 871         for (i = 0; i < ARRAY_SIZE(default_classname_table); i++) {
 872                 debug_add_class(default_classname_table[i]);
 873         }
 874
 875         for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
 876                 debug_backends[i].log_level = -1;
 877                 debug_backends[i].new_log_level = -1;
 878         }
 879 }
 880
 881 void debug_set_settings(struct debug_settings *settings,
 882                         const char *logging_param,
 883                         int syslog_level, bool syslog_only)
 884 {
 885         char fake_param[256];
 886         size_t len = 0;
 887
 888         /*
 889          * This forces in some smb.conf derived values into the debug
 890          * system. There are no pointers in this structure, so we can
 891          * just structure-assign it in
 892          */
 893         state.settings = *settings;
 894
 895         /*
 896          * If 'logging' is not set, create backend settings from
 897          * deprecated 'syslog' and 'syslog only' parameters
 898          */
 899         if (logging_param != NULL) {
 900                 len = strlen(logging_param);
 901         }
 902         if (len == 0) {
 903                 if (syslog_only) {
 904                         snprintf(fake_param, sizeof(fake_param),
 905                                  "syslog@%d", syslog_level - 1);
 906                 } else {
 907                         snprintf(fake_param, sizeof(fake_param),
 908                                  "syslog@%d file@%d", syslog_level -1,
 909                                  MAX_DEBUG_LEVEL);
 910                 }
 911
 912                 logging_param = fake_param;
 913         }
 914
 915         debug_set_backends(logging_param);
 916 }
 917
 918 /**
 919   control the name of the logfile and whether logging will be to stdout, stderr
 920   or a file, and set up syslog
 921
 922   new_log indicates the destination for the debug log (an enum in
 923   order of precedence - once set to DEBUG_FILE, it is not possible to
 924   reset to DEBUG_STDOUT for example.  This makes it easy to override
 925   for debug to stderr on the command line, as the smb.conf cannot
 926   reset it back to file-based logging
 927 */
 928 void setup_logging(const char *prog_name, enum debug_logtype new_logtype)
 929 {
 930         debug_init();
 931         if (state.logtype < new_logtype) {
 932                 state.logtype = new_logtype;
 933         }
 934         if (prog_name) {
 935                 const char *p = strrchr(prog_name, '/');
 936
 937                 if (p) {
 938                         prog_name = p + 1;
 939                 }
 940
 941                 state.prog_name = prog_name;
 942         }
 943         reopen_logs_internal();
 944 }
 945
 946 /***************************************************************************
 947  Set the logfile name.
 948 **************************************************************************/
 949
 950 void debug_set_logfile(const char *name)
 951 {
 952         if (name == NULL || *name == 0) {
 953                 /* this copes with calls when smb.conf is not loaded yet */
 954                 return;
 955         }
 956         TALLOC_FREE(state.debugf);
 957         state.debugf = talloc_strdup(NULL, name);
 958 }
 959
 960 static void debug_close_fd(int fd)
 961 {
 962         if (fd > 2) {
 963                 close(fd);
 964         }
 965 }
 966
 967 bool debug_get_output_is_stderr(void)
 968 {
 969         return (state.logtype == DEBUG_DEFAULT_STDERR) || (state.logtype == DEBUG_STDERR);
 970 }
 971
 972 bool debug_get_output_is_stdout(void)
 973 {
 974         return (state.logtype == DEBUG_DEFAULT_STDOUT) || (state.logtype == DEBUG_STDOUT);
 975 }
 976
 977 void debug_set_callback(void *private_ptr, debug_callback_fn fn)
 978 {
 979         debug_init();
 980         if (fn) {
 981                 state.logtype = DEBUG_CALLBACK;
 982                 state.callback_private = private_ptr;
 983                 state.callback = fn;
 984         } else {
 985                 state.logtype = DEBUG_DEFAULT_STDERR;
 986                 state.callback_private = NULL;
 987                 state.callback = NULL;
 988         }
 989 }
 990
 991 static void debug_callback_log(const char *msg, int msg_level)
 992 {
 993         size_t msg_len = strlen(msg);
 994         char msg_copy[msg_len];
 995
 996         if ((msg_len > 0) && (msg[msg_len-1] == '\n')) {
 997                 memcpy(msg_copy, msg, msg_len-1);
 998                 msg_copy[msg_len-1] = '\0';
 999                 msg = msg_copy;
1000         }
1001
1002         state.callback(state.callback_private, msg_level, msg);
1003 }
1004
1005 /**************************************************************************
1006  reopen the log files
1007  note that we now do this unconditionally
1008  We attempt to open the new debug fp before closing the old. This means
1009  if we run out of fd's we just keep using the old fd rather than aborting.
1010  Fix from dgibson@linuxcare.com.
1011 **************************************************************************/
1012
1013 /**
1014   reopen the log file (usually called because the log file name might have changed)
1015 */
1016 bool reopen_logs_internal(void)
1017 {
1018         mode_t oldumask;
1019         int new_fd = 0;
1020         int old_fd = 0;
1021         bool ret = true;
1022
1023         if (state.reopening_logs) {
1024                 return true;
1025         }
1026
1027         /* Now clear the SIGHUP induced flag */
1028         state.schedule_reopen_logs = false;
1029
1030         switch (state.logtype) {
1031         case DEBUG_CALLBACK:
1032                 return true;
1033         case DEBUG_STDOUT:
1034         case DEBUG_DEFAULT_STDOUT:
1035                 debug_close_fd(state.fd);
1036                 state.fd = 1;
1037                 return true;
1038
1039         case DEBUG_DEFAULT_STDERR:
1040         case DEBUG_STDERR:
1041                 debug_close_fd(state.fd);
1042                 state.fd = 2;
1043                 return true;
1044
1045         case DEBUG_FILE:
1046                 break;
1047         }
1048
1049         oldumask = umask( 022 );
1050
1051         if (!state.debugf) {
1052                 return false;
1053         }
1054
1055         state.reopening_logs = true;
1056
1057         new_fd = open( state.debugf, O_WRONLY|O_APPEND|O_CREAT, 0644);
1058
1059         if (new_fd == -1) {
1060                 log_overflow = true;
1061                 DEBUG(0, ("Unable to open new log file '%s': %s\n", state.debugf, strerror(errno)));
1062                 log_overflow = false;
1063                 ret = false;
1064         } else {
1065                 smb_set_close_on_exec(new_fd);
1066                 old_fd = state.fd;
1067                 state.fd = new_fd;
1068                 debug_close_fd(old_fd);
1069         }
1070
1071         /* Fix from klausr@ITAP.Physik.Uni-Stuttgart.De
1072          * to fix problem where smbd's that generate less
1073          * than 100 messages keep growing the log.
1074          */
1075         force_check_log_size();
1076         (void)umask(oldumask);
1077
1078         /* Take over stderr to catch output into logs */
1079         if (state.fd > 0) {
1080                 if (dup2(state.fd, 2) == -1) {
1081                         /* Close stderr too, if dup2 can't point it -
1082                            at the logfile.  There really isn't much
1083                            that can be done on such a fundamental
1084                            failure... */
1085                         close_low_fd(2);
1086                 }
1087         }
1088
1089         state.reopening_logs = false;
1090
1091         return ret;
1092 }
1093
1094 /**************************************************************************
1095  Force a check of the log size.
1096  ***************************************************************************/
1097
1098 void force_check_log_size( void )
1099 {
1100         debug_count = 100;
1101 }
1102
1103 _PUBLIC_ void debug_schedule_reopen_logs(void)
1104 {
1105         state.schedule_reopen_logs = true;
1106 }
1107
1108
1109 /***************************************************************************
1110  Check to see if there is any need to check if the logfile has grown too big.
1111 **************************************************************************/
1112
1113 bool need_to_check_log_size( void )
1114 {
1115         int maxlog;
1116
1117         if( debug_count < 100)
1118                 return( false );
1119
1120         maxlog = state.settings.max_log_size * 1024;
1121         if ( state.fd <=2 || maxlog <= 0 ) {
1122                 debug_count = 0;
1123                 return(false);
1124         }
1125         return( true );
1126 }
1127
1128 /**************************************************************************
1129  Check to see if the log has grown to be too big.
1130  **************************************************************************/
1131
1132 void check_log_size( void )
1133 {
1134         int         maxlog;
1135         struct stat st;
1136
1137         /*
1138          *  We need to be root to check/change log-file, skip this and let the main
1139          *  loop check do a new check as root.
1140          */
1141
1142 #if _SAMBA_BUILD_ == 3
1143         if (geteuid() != sec_initial_uid())
1144 #else
1145         if( geteuid() != 0)
1146 #endif
1147         {
1148                 /* We don't check sec_initial_uid() here as it isn't
1149                  * available in common code and we don't generally
1150                  * want to rotate and the possibly lose logs in
1151                  * make test or the build farm */
1152                 return;
1153         }
1154
1155         if(log_overflow || (!state.schedule_reopen_logs && !need_to_check_log_size())) {
1156                 return;
1157         }
1158
1159         maxlog = state.settings.max_log_size * 1024;
1160
1161         if (state.schedule_reopen_logs) {
1162             (void)reopen_logs_internal();
1163         }
1164
1165         if (maxlog && (fstat(state.fd, &st) == 0
1166             && st.st_size > maxlog )) {
1167                 (void)reopen_logs_internal();
1168                 if (state.fd > 2 && (fstat(state.fd, &st) == 0
1169                                      && st.st_size > maxlog)) {
1170                         char name[strlen(state.debugf) + 5];
1171
1172                         snprintf(name, sizeof(name), "%s.old", state.debugf);
1173
1174                         (void)rename(state.debugf, name);
1175
1176                         if (!reopen_logs_internal()) {
1177                                 /* We failed to reopen a log - continue using the old name. */
1178                                 (void)rename(name, state.debugf);
1179                         }
1180                 }
1181         }
1182
1183         /*
1184          * Here's where we need to panic if state.fd == 0 or -1 (invalid values)
1185          */
1186
1187         if (state.fd <= 0) {
1188                 /* This code should only be reached in very strange
1189                  * circumstances. If we merely fail to open the new log we
1190                  * should stick with the old one. ergo this should only be
1191                  * reached when opening the logs for the first time: at
1192                  * startup or when the log level is increased from zero.
1193                  * -dwg 6 June 2000
1194                  */
1195                 int fd = open( "/dev/console", O_WRONLY, 0);
1196                 if (fd != -1) {
1197                         smb_set_close_on_exec(fd);
1198                         state.fd = fd;
1199                         DEBUG(0,("check_log_size: open of debug file %s failed - using console.\n",
1200                                         state.debugf ));
1201                 } else {
1202                         /*
1203                          * We cannot continue without a debug file handle.
1204                          */
1205                         abort();
1206                 }
1207         }
1208         debug_count = 0;
1209 }
1210
1211 /*************************************************************************
1212  Write an debug message on the debugfile.
1213  This is called by dbghdr() and format_debug_text().
1214 ************************************************************************/
1215
1216 static void Debug1(const char *msg)
1217 {
1218         int old_errno = errno;
1219
1220         debug_count++;
1221
1222         switch(state.logtype) {
1223         case DEBUG_CALLBACK:
1224                 debug_callback_log(msg, current_msg_level);
1225                 break;
1226         case DEBUG_STDOUT:
1227         case DEBUG_STDERR:
1228         case DEBUG_DEFAULT_STDOUT:
1229         case DEBUG_DEFAULT_STDERR:
1230                 if (state.fd > 0) {
1231                         ssize_t ret;
1232                         do {
1233                                 ret = write(state.fd, msg, strlen(msg));
1234                         } while (ret == -1 && errno == EINTR);
1235                 }
1236                 break;
1237         case DEBUG_FILE:
1238                 debug_backends_log(msg, current_msg_level);
1239                 break;
1240         };
1241
1242         errno = old_errno;
1243 }
1244
1245 /**************************************************************************
1246  Print the buffer content via Debug1(), then reset the buffer.
1247  Input:  none
1248  Output: none
1249 ****************************************************************************/
1250
1251 static void bufr_print( void )
1252 {
1253         format_bufr[format_pos] = '\0';
1254         (void)Debug1(format_bufr);
1255         format_pos = 0;
1256 }
1257
1258 /***************************************************************************
1259  Format the debug message text.
1260
1261  Input:  msg - Text to be added to the "current" debug message text.
1262
1263  Output: none.
1264
1265  Notes:  The purpose of this is two-fold.  First, each call to syslog()
1266          (used by Debug1(), see above) generates a new line of syslog
1267          output.  This is fixed by storing the partial lines until the
1268          newline character is encountered.  Second, printing the debug
1269          message lines when a newline is encountered allows us to add
1270          spaces, thus indenting the body of the message and making it
1271          more readable.
1272 **************************************************************************/
1273
1274 static void format_debug_text( const char *msg )
1275 {
1276         size_t i;
1277         bool timestamp = (state.logtype == DEBUG_FILE && (state.settings.timestamp_logs));
1278
1279         debug_init();
1280
1281         for( i = 0; msg[i]; i++ ) {
1282                 /* Indent two spaces at each new line. */
1283                 if(timestamp && 0 == format_pos) {
1284                         format_bufr[0] = format_bufr[1] = ' ';
1285                         format_pos = 2;
1286                 }
1287
1288                 /* If there's room, copy the character to the format buffer. */
1289                 if (format_pos < FORMAT_BUFR_SIZE - 1)
1290                         format_bufr[format_pos++] = msg[i];
1291
1292                 /* If a newline is encountered, print & restart. */
1293                 if( '\n' == msg[i] )
1294                         bufr_print();
1295
1296                 /* If the buffer is full dump it out, reset it, and put out a line
1297                  * continuation indicator.
1298                  */
1299                 if (format_pos >= FORMAT_BUFR_SIZE - 1) {
1300                         bufr_print();
1301                         (void)Debug1( " +>\n" );
1302                 }
1303         }
1304
1305         /* Just to be safe... */
1306         format_bufr[format_pos] = '\0';
1307 }
1308
1309 /***************************************************************************
1310  Flush debug output, including the format buffer content.
1311
1312  Input:  none
1313  Output: none
1314 ***************************************************************************/
1315
1316 void dbgflush( void )
1317 {
1318         bufr_print();
1319 }
1320
1321 /***************************************************************************
1322  Print a Debug Header.
1323
1324  Input:  level    - Debug level of the message (not the system-wide debug
1325                     level. )
1326          cls      - Debuglevel class of the calling module.
1327          location - Pointer to a string containing the name of the file
1328                     from which this function was called, or an empty string
1329                     if the __FILE__ macro is not implemented.
1330          func     - Pointer to a string containing the name of the function
1331                     from which this function was called, or an empty string
1332                     if the __FUNCTION__ macro is not implemented.
1333
1334  Output: Always true.  This makes it easy to fudge a call to dbghdr()
1335          in a macro, since the function can be called as part of a test.
1336          Eg: ( (level <= DEBUGLEVEL) && (dbghdr(level,"",line)) )
1337
1338  Notes:  This function takes care of setting current_msg_level.
1339
1340 ****************************************************************************/
1341
1342 bool dbghdrclass(int level, int cls, const char *location, const char *func)
1343 {
1344         /* Ensure we don't lose any real errno value. */
1345         int old_errno = errno;
1346         bool verbose = false;
1347         char header_str[300];
1348         size_t hs_len;
1349         struct timeval tv;
1350         struct timeval_buf tvbuf;
1351
1352         if( format_pos ) {
1353                 /* This is a fudge.  If there is stuff sitting in the format_bufr, then
1354                  * the *right* thing to do is to call
1355                  *   format_debug_text( "\n" );
1356                  * to write the remainder, and then proceed with the new header.
1357                  * Unfortunately, there are several places in the code at which
1358                  * the DEBUG() macro is used to build partial lines.  That in mind,
1359                  * we'll work under the assumption that an incomplete line indicates
1360                  * that a new header is *not* desired.
1361                  */
1362                 return( true );
1363         }
1364
1365         /* Set current_msg_level. */
1366         current_msg_level = level;
1367
1368         /* Don't print a header if we're logging to stdout. */
1369         if ( state.logtype != DEBUG_FILE ) {
1370                 return( true );
1371         }
1372
1373         /* Print the header if timestamps are turned on.  If parameters are
1374          * not yet loaded, then default to timestamps on.
1375          */
1376         if (!(state.settings.timestamp_logs ||
1377               state.settings.debug_prefix_timestamp)) {
1378                 return true;
1379         }
1380
1381         GetTimeOfDay(&tv);
1382         timeval_str_buf(&tv, false, state.settings.debug_hires_timestamp,
1383                         &tvbuf);
1384
1385         hs_len = snprintf(header_str, sizeof(header_str), "[%s, %2d",
1386                           tvbuf.buf, level);
1387         if (hs_len >= sizeof(header_str)) {
1388                 goto full;
1389         }
1390
1391         if (unlikely(DEBUGLEVEL_CLASS[ cls ] >= 10)) {
1392                 verbose = true;
1393         }
1394
1395         if (verbose || state.settings.debug_pid) {
1396                 hs_len += snprintf(
1397                         header_str + hs_len, sizeof(header_str) - hs_len,
1398                         ", pid=%u", (unsigned int)getpid());
1399                 if (hs_len >= sizeof(header_str)) {
1400                         goto full;
1401                 }
1402         }
1403
1404         if (verbose || state.settings.debug_uid) {
1405                 hs_len += snprintf(
1406                         header_str + hs_len, sizeof(header_str) - hs_len,
1407                         ", effective(%u, %u), real(%u, %u)",
1408                         (unsigned int)geteuid(), (unsigned int)getegid(),
1409                         (unsigned int)getuid(), (unsigned int)getgid());
1410                 if (hs_len >= sizeof(header_str)) {
1411                         goto full;
1412                 }
1413         }
1414
1415         if ((verbose || state.settings.debug_class)
1416             && (cls != DBGC_ALL)) {
1417                 hs_len += snprintf(
1418                         header_str + hs_len, sizeof(header_str) - hs_len,
1419                         ", class=%s", classname_table[cls]);
1420                 if (hs_len >= sizeof(header_str)) {
1421                         goto full;
1422                 }
1423         }
1424
1425         /*
1426          * No +=, see man man strlcat
1427          */
1428         hs_len = strlcat(header_str, "] ", sizeof(header_str));
1429         if (hs_len >= sizeof(header_str)) {
1430                 goto full;
1431         }
1432
1433         if (!state.settings.debug_prefix_timestamp) {
1434                 hs_len += snprintf(
1435                         header_str + hs_len, sizeof(header_str) - hs_len,
1436                         "%s(%s)\n", location, func);
1437                 if (hs_len >= sizeof(header_str)) {
1438                         goto full;
1439                 }
1440         }
1441
1442 full:
1443         (void)Debug1(header_str);
1444
1445         errno = old_errno;
1446         return( true );
1447 }
1448
1449 /***************************************************************************
1450  Add text to the body of the "current" debug message via the format buffer.
1451
1452   Input:  format_str  - Format string, as used in printf(), et. al.
1453           ...         - Variable argument list.
1454
1455   ..or..  va_alist    - Old style variable parameter list starting point.
1456
1457   Output: Always true.  See dbghdr() for more info, though this is not
1458           likely to be used in the same way.
1459
1460 ***************************************************************************/
1461
1462 static inline bool __dbgtext_va(const char *format_str, va_list ap) PRINTF_ATTRIBUTE(1,0);
1463 static inline bool __dbgtext_va(const char *format_str, va_list ap)
1464 {
1465         char *msgbuf = NULL;
1466         bool ret = true;
1467         int res;
1468
1469         res = vasprintf(&msgbuf, format_str, ap);
1470         if (res != -1) {
1471                 format_debug_text(msgbuf);
1472         } else {
1473                 ret = false;
1474         }
1475         SAFE_FREE(msgbuf);
1476         return ret;
1477 }
1478
1479 bool dbgtext_va(const char *format_str, va_list ap)
1480 {
1481         return __dbgtext_va(format_str, ap);
1482 }
1483
1484 bool dbgtext(const char *format_str, ... )
1485 {
1486         va_list ap;
1487         bool ret;
1488
1489         va_start(ap, format_str);
1490         ret = __dbgtext_va(format_str, ap);
1491         va_end(ap);
1492
1493         return ret;
1494 }