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