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