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