Coverage Report

Created: 2026-09-03 07:24

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