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 107 : 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 107 : if (level < 0 || (size_t)level >= ARRAY_SIZE(priority_map))
234 0 : priority = LOG_DEBUG;
235 : else
236 107 : priority = priority_map[level];
237 :
238 107 : 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 2865 : static void debug_file_log(int msg_level, const char *msg, size_t msg_len)
290 : {
291 5457 : struct iovec iov[] = {
292 : {
293 : .iov_base = discard_const(state.header_str),
294 2865 : .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 2865 : check_log_size();
305 :
306 2865 : if (dbgc_config[current_msg_class].fd != -1) {
307 896 : fd = dbgc_config[current_msg_class].fd;
308 : } else {
309 1969 : fd = dbgc_config[DBGC_ALL].fd;
310 : }
311 :
312 : do {
313 2865 : ret = writev(fd, iov, ARRAY_SIZE(iov));
314 2865 : } while (ret == -1 && errno == EINTR);
315 2865 : }
316 :
317 : #ifdef WITH_SYSLOG
318 46010 : static void debug_syslog_reload(bool enabled, bool previously_enabled,
319 : const char *prog_name, char *option)
320 : {
321 46010 : if (enabled && !previously_enabled) {
322 7017 : const char *ident = NULL;
323 7017 : if ((prog_name != NULL) && (prog_name[0] != '\0')) {
324 2649 : ident = prog_name;
325 : }
326 : #ifdef LOG_DAEMON
327 7017 : 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 7017 : return;
333 : }
334 :
335 38993 : if (!enabled && previously_enabled) {
336 0 : closelog();
337 : }
338 : }
339 :
340 107 : static void debug_syslog_log(int msg_level, const char *msg, size_t msg_len)
341 : {
342 : int priority;
343 :
344 107 : 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 107 : priority |= SYSLOG_FACILITY;
351 :
352 107 : if (state.hs_len > 0) {
353 66 : syslog(priority, "%s", state.header_str);
354 : }
355 107 : syslog(priority, "%s", msg);
356 107 : }
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 46010 : static void debug_gpfs_reload(bool enabled, bool previously_enabled,
407 : const char *prog_name, char *option)
408 : {
409 46010 : gpfswrap_init();
410 :
411 46010 : if (enabled && !previously_enabled) {
412 0 : gpfswrap_init_trace();
413 0 : return;
414 : }
415 :
416 46010 : if (!enabled && previously_enabled) {
417 0 : gpfswrap_fini_trace();
418 0 : return;
419 : }
420 :
421 46010 : 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 46010 : static void debug_ringbuf_reload(bool enabled, bool previously_enabled,
465 : const char *prog_name, char *option)
466 : {
467 : bool cmp;
468 46010 : size_t optlen = strlen(DEBUG_RINGBUF_SIZE_OPT);
469 :
470 46010 : debug_ringbuf_size = DEBUG_RINGBUF_SIZE;
471 46010 : debug_ringbuf_ofs = 0;
472 :
473 46010 : SAFE_FREE(debug_ringbuf);
474 :
475 46010 : if (!enabled) {
476 46010 : 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 112462 : static struct debug_backend *debug_find_backend(const char *name)
580 : {
581 : unsigned i;
582 :
583 139855 : for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
584 139853 : if (strcmp(name, debug_backends[i].name) == 0) {
585 112460 : return &debug_backends[i];
586 : }
587 : }
588 :
589 2 : return NULL;
590 : }
591 :
592 : /*
593 : * parse "backend[:option][@loglevel]
594 : */
595 73391 : 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 73391 : backend_name_option = strtok_r(tok, "@\0", &saveptr);
605 73391 : if (backend_name_option == NULL) {
606 2 : return;
607 : }
608 :
609 73391 : backend_level = strtok_r(NULL, "\0", &saveptr);
610 :
611 : /*
612 : * Now parse backend[:option]
613 : */
614 73391 : backend_name = strtok_r(backend_name_option, ":\0", &saveptr);
615 73391 : if (backend_name == NULL) {
616 0 : return;
617 : }
618 :
619 73391 : backend_option = strtok_r(NULL, "\0", &saveptr);
620 :
621 : /*
622 : * Find and update backend
623 : */
624 73391 : b = debug_find_backend(backend_name);
625 73391 : if (b == NULL) {
626 2 : return;
627 : }
628 :
629 73389 : if (backend_level == NULL) {
630 18625 : b->new_log_level = MAX_DEBUG_LEVEL;
631 : } else {
632 54764 : b->new_log_level = atoi(backend_level);
633 : }
634 :
635 73389 : 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 46010 : static void debug_set_backends(const char *param)
648 46010 : {
649 46010 : size_t str_len = strlen(param);
650 46010 : 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 276060 : for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
659 230050 : SAFE_FREE(debug_backends[i].option);
660 230050 : debug_backends[i].new_log_level = -1;
661 : }
662 :
663 46010 : memcpy(str, param, str_len + 1);
664 :
665 46010 : tok = strtok_r(str, LIST_SEP, &saveptr);
666 46010 : if (tok == NULL) {
667 0 : return;
668 : }
669 :
670 155370 : while (tok != NULL) {
671 73391 : debug_backend_parse_token(tok);
672 73391 : tok = strtok_r(NULL, LIST_SEP, &saveptr);
673 : }
674 :
675 : /*
676 : * Let backends react to config changes
677 : */
678 276060 : for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
679 230050 : struct debug_backend *b = &debug_backends[i];
680 :
681 230050 : if (b->reload) {
682 138030 : bool enabled = b->new_log_level > -1;
683 138030 : bool previously_enabled = b->log_level > -1;
684 :
685 138030 : b->reload(enabled, previously_enabled, state.prog_name,
686 : b->option);
687 : }
688 230050 : b->log_level = b->new_log_level;
689 : }
690 : }
691 :
692 2865 : 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 2865 : state.msg_no_nl[0] = '\0';
702 :
703 17190 : for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
704 14325 : if (msg_level <= debug_backends[i].log_level) {
705 2972 : debug_backends[i].log(msg_level, msg, msg_len);
706 : }
707 : }
708 :
709 : /* Only log the header once */
710 2865 : state.hs_len = 0;
711 2865 : }
712 :
713 433407642 : int debuglevel_get_class(size_t idx)
714 : {
715 433407642 : return dbgc_config[idx].loglevel;
716 : }
717 :
718 1989 : void debuglevel_set_class(size_t idx, int level)
719 : {
720 1989 : dbgc_config[idx].loglevel = level;
721 1989 : }
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 225 : void gfree_debugsyms(void)
772 : {
773 : unsigned i;
774 :
775 225 : TALLOC_FREE(classname_table);
776 :
777 225 : if ( dbgc_config != debug_class_list_initial ) {
778 225 : TALLOC_FREE( dbgc_config );
779 225 : dbgc_config = discard_const_p(struct debug_class,
780 : debug_class_list_initial);
781 : }
782 :
783 225 : debug_num_classes = 0;
784 :
785 225 : state.initialized = false;
786 :
787 1350 : for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
788 1125 : SAFE_FREE(debug_backends[i].option);
789 : }
790 225 : }
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 = NULL;
799 : size_t i;
800 : /* prepare strings */
801 0 : for (i = 0; i < debug_num_classes; i++) {
802 0 : buf = talloc_asprintf_append(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 0 : if (buf == NULL) {
808 0 : return NULL;
809 : }
810 : }
811 0 : return buf;
812 : }
813 :
814 : /****************************************************************************
815 : Utility to translate names to debug class index's (internal version).
816 : ****************************************************************************/
817 :
818 534907 : static int debug_lookup_classname_int(const char* classname)
819 : {
820 : size_t i;
821 :
822 534907 : if (classname == NULL) {
823 0 : return -1;
824 : }
825 :
826 10554618 : for (i=0; i < debug_num_classes; i++) {
827 10019711 : char *entry = classname_table[i];
828 10019711 : if (entry != NULL && strcmp(classname, entry)==0) {
829 0 : return i;
830 : }
831 : }
832 534907 : return -1;
833 : }
834 :
835 : /****************************************************************************
836 : Add a new debug class to the system.
837 : ****************************************************************************/
838 :
839 534907 : int debug_add_class(const char *classname)
840 : {
841 : int ndx;
842 534907 : struct debug_class *new_class_list = NULL;
843 : char **new_name_list;
844 : int default_level;
845 :
846 534907 : if (classname == NULL) {
847 0 : return -1;
848 : }
849 :
850 : /* check the init has yet been called */
851 534907 : debug_init();
852 :
853 534907 : ndx = debug_lookup_classname_int(classname);
854 534907 : if (ndx >= 0) {
855 0 : return ndx;
856 : }
857 534907 : ndx = debug_num_classes;
858 :
859 534907 : if (dbgc_config == debug_class_list_initial) {
860 : /* Initial loading... */
861 13913 : new_class_list = NULL;
862 : } else {
863 520994 : new_class_list = dbgc_config;
864 : }
865 :
866 534907 : default_level = dbgc_config[DBGC_ALL].loglevel;
867 :
868 534907 : new_class_list = talloc_realloc(NULL,
869 : new_class_list,
870 : struct debug_class,
871 : ndx + 1);
872 534907 : if (new_class_list == NULL) {
873 0 : return -1;
874 : }
875 :
876 534907 : dbgc_config = new_class_list;
877 :
878 534907 : dbgc_config[ndx] = (struct debug_class) {
879 : .loglevel = default_level,
880 : .fd = -1,
881 : };
882 :
883 534907 : new_name_list = talloc_realloc(NULL, classname_table, char *, ndx + 1);
884 534907 : if (new_name_list == NULL) {
885 0 : return -1;
886 : }
887 534907 : classname_table = new_name_list;
888 :
889 534907 : classname_table[ndx] = talloc_strdup(classname_table, classname);
890 534907 : if (classname_table[ndx] == NULL) {
891 0 : return -1;
892 : }
893 :
894 534907 : debug_num_classes = ndx + 1;
895 :
896 534907 : return ndx;
897 : }
898 :
899 : /****************************************************************************
900 : Utility to translate names to debug class index's (public version).
901 : ****************************************************************************/
902 :
903 0 : static int debug_lookup_classname(const char *classname)
904 : {
905 : int ndx;
906 :
907 0 : if (classname == NULL || !*classname)
908 0 : return -1;
909 :
910 0 : ndx = debug_lookup_classname_int(classname);
911 :
912 0 : if (ndx != -1)
913 0 : return ndx;
914 :
915 0 : DBG_WARNING("Unknown classname[%s] -> adding it...\n", classname);
916 0 : return debug_add_class(classname);
917 : }
918 :
919 : /****************************************************************************
920 : Dump the current registered debug levels.
921 : ****************************************************************************/
922 :
923 65421 : static void debug_dump_status(int level)
924 : {
925 : size_t q;
926 :
927 65421 : DEBUG(level, ("INFO: Current debug levels:\n"));
928 2551850 : for (q = 0; q < debug_num_classes; q++) {
929 2486429 : const char *classname = classname_table[q];
930 2486429 : DEBUGADD(level, (" %s: %d\n",
931 : classname,
932 : dbgc_config[q].loglevel));
933 : }
934 65421 : }
935 :
936 0 : static bool debug_parse_param(char *param)
937 : {
938 : char *class_name;
939 0 : char *class_file = NULL;
940 : char *class_level;
941 0 : char *saveptr = NULL;
942 : int ndx;
943 :
944 0 : class_name = strtok_r(param, ":", &saveptr);
945 0 : if (class_name == NULL) {
946 0 : return false;
947 : }
948 :
949 0 : class_level = strtok_r(NULL, "@\0", &saveptr);
950 0 : if (class_level == NULL) {
951 0 : return false;
952 : }
953 :
954 0 : class_file = strtok_r(NULL, "\0", &saveptr);
955 :
956 0 : ndx = debug_lookup_classname(class_name);
957 0 : if (ndx == -1) {
958 0 : return false;
959 : }
960 :
961 0 : dbgc_config[ndx].loglevel = atoi(class_level);
962 :
963 0 : if (class_file == NULL) {
964 0 : return true;
965 : }
966 :
967 0 : TALLOC_FREE(dbgc_config[ndx].logfile);
968 :
969 0 : dbgc_config[ndx].logfile = talloc_strdup(NULL, class_file);
970 0 : if (dbgc_config[ndx].logfile == NULL) {
971 0 : return false;
972 : }
973 0 : return true;
974 : }
975 :
976 : /****************************************************************************
977 : Parse the debug levels from smb.conf. Example debug level string:
978 : 3 tdb:5 printdrivers:7
979 : Note: the 1st param has no "name:" preceding it.
980 : ****************************************************************************/
981 :
982 65421 : bool debug_parse_levels(const char *params_str)
983 65421 : {
984 65421 : size_t str_len = strlen(params_str);
985 65421 : char str[str_len+1];
986 : char *tok, *saveptr;
987 : size_t i;
988 :
989 : /* Just in case */
990 65421 : debug_init();
991 :
992 65421 : memcpy(str, params_str, str_len+1);
993 :
994 65421 : tok = strtok_r(str, LIST_SEP, &saveptr);
995 65421 : if (tok == NULL) {
996 0 : return true;
997 : }
998 :
999 : /* Allow DBGC_ALL to be specified w/o requiring its class name e.g."10"
1000 : * v.s. "all:10", this is the traditional way to set DEBUGLEVEL
1001 : */
1002 65421 : if (isdigit(tok[0])) {
1003 65421 : dbgc_config[DBGC_ALL].loglevel = atoi(tok);
1004 65421 : tok = strtok_r(NULL, LIST_SEP, &saveptr);
1005 : } else {
1006 0 : dbgc_config[DBGC_ALL].loglevel = 0;
1007 : }
1008 :
1009 : /* Array is debug_num_classes long */
1010 2486429 : for (i = DBGC_ALL+1; i < debug_num_classes; i++) {
1011 2421008 : dbgc_config[i].loglevel = dbgc_config[DBGC_ALL].loglevel;
1012 2421008 : TALLOC_FREE(dbgc_config[i].logfile);
1013 : }
1014 :
1015 115910 : while (tok != NULL) {
1016 : bool ok;
1017 :
1018 0 : ok = debug_parse_param(tok);
1019 0 : if (!ok) {
1020 0 : DEBUG(0,("debug_parse_params: unrecognized debug "
1021 : "class name or format [%s]\n", tok));
1022 0 : return false;
1023 : }
1024 :
1025 0 : tok = strtok_r(NULL, LIST_SEP, &saveptr);
1026 : }
1027 :
1028 65421 : debug_dump_status(5);
1029 :
1030 65421 : return true;
1031 : }
1032 :
1033 : /* setup for logging of talloc warnings */
1034 0 : static void talloc_log_fn(const char *msg)
1035 : {
1036 0 : DEBUG(0,("%s", msg));
1037 0 : }
1038 :
1039 21551 : void debug_setup_talloc_log(void)
1040 : {
1041 21551 : talloc_set_log_fn(talloc_log_fn);
1042 21551 : }
1043 :
1044 :
1045 : /****************************************************************************
1046 : Init debugging (one time stuff)
1047 : ****************************************************************************/
1048 :
1049 809926 : static void debug_init(void)
1050 : {
1051 : size_t i;
1052 :
1053 809926 : if (state.initialized)
1054 796013 : return;
1055 :
1056 13913 : state.initialized = true;
1057 :
1058 13913 : debug_setup_talloc_log();
1059 :
1060 542607 : for (i = 0; i < ARRAY_SIZE(default_classname_table); i++) {
1061 528694 : debug_add_class(default_classname_table[i]);
1062 : }
1063 13913 : dbgc_config[DBGC_ALL].fd = 2;
1064 :
1065 83478 : for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
1066 69565 : debug_backends[i].log_level = -1;
1067 69565 : debug_backends[i].new_log_level = -1;
1068 : }
1069 : }
1070 :
1071 46010 : void debug_set_settings(struct debug_settings *settings,
1072 : const char *logging_param,
1073 : int syslog_level, bool syslog_only)
1074 : {
1075 : char fake_param[256];
1076 46010 : size_t len = 0;
1077 :
1078 : /*
1079 : * This forces in some smb.conf derived values into the debug
1080 : * system. There are no pointers in this structure, so we can
1081 : * just structure-assign it in
1082 : */
1083 46010 : state.settings = *settings;
1084 :
1085 : /*
1086 : * If 'logging' is not set, create backend settings from
1087 : * deprecated 'syslog' and 'syslog only' parameters
1088 : */
1089 46010 : if (logging_param != NULL) {
1090 46010 : len = strlen(logging_param);
1091 : }
1092 46010 : if (len == 0) {
1093 27383 : if (syslog_only) {
1094 2 : snprintf(fake_param, sizeof(fake_param),
1095 : "syslog@%d", syslog_level - 1);
1096 : } else {
1097 27381 : snprintf(fake_param, sizeof(fake_param),
1098 : "syslog@%d file@%d", syslog_level -1,
1099 : MAX_DEBUG_LEVEL);
1100 : }
1101 :
1102 27383 : logging_param = fake_param;
1103 : }
1104 :
1105 46010 : debug_set_backends(logging_param);
1106 46010 : }
1107 :
1108 0 : static void ensure_hostname(void)
1109 : {
1110 : int ret;
1111 :
1112 0 : if (state.hostname[0] != '\0') {
1113 0 : return;
1114 : }
1115 :
1116 0 : ret = gethostname(state.hostname, sizeof(state.hostname));
1117 0 : if (ret != 0) {
1118 0 : strlcpy(state.hostname, "unknown", sizeof(state.hostname));
1119 0 : return;
1120 : }
1121 :
1122 : /*
1123 : * Ensure NUL termination, since POSIX isn't clear about that.
1124 : *
1125 : * Don't worry about truncating at the first '.' or similar,
1126 : * since this is usually not fully qualified. Trying to
1127 : * truncate opens up the multibyte character gates of hell.
1128 : */
1129 0 : state.hostname[sizeof(state.hostname) - 1] = '\0';
1130 : }
1131 :
1132 0 : void debug_set_hostname(const char *name)
1133 : {
1134 0 : strlcpy(state.hostname, name, sizeof(state.hostname));
1135 0 : }
1136 :
1137 : /**
1138 : * Ensure debug logs are initialised.
1139 : *
1140 : * setup_logging() is called to direct logging to the correct outputs, whether
1141 : * those be stderr, stdout, files, or syslog, and set the program name used in
1142 : * the logs. It can be called multiple times.
1143 : *
1144 : * There is an order of precedence to the log type. Once set to DEBUG_FILE, it
1145 : * cannot be reset DEFAULT_DEBUG_STDERR, but can be set to DEBUG_STDERR, after
1146 : * which DEBUG_FILE is unavailable). This makes it possible to override for
1147 : * debug to stderr on the command line, as the smb.conf cannot reset it back
1148 : * to file-based logging. See enum debug_logtype.
1149 : *
1150 : * @param prog_name the program name. Directory path component will be
1151 : * ignored.
1152 : *
1153 : * @param new_logtype the requested destination for the debug log,
1154 : * as an enum debug_logtype.
1155 : */
1156 9574 : void setup_logging(const char *prog_name, enum debug_logtype new_logtype)
1157 : {
1158 9574 : debug_init();
1159 9574 : if (state.logtype < new_logtype) {
1160 940 : state.logtype = new_logtype;
1161 : }
1162 9574 : if (prog_name) {
1163 9574 : const char *p = strrchr(prog_name, '/');
1164 :
1165 9574 : if (p) {
1166 316 : prog_name = p + 1;
1167 : }
1168 :
1169 9574 : strlcpy(state.prog_name, prog_name, sizeof(state.prog_name));
1170 : }
1171 9574 : reopen_logs_internal();
1172 9574 : }
1173 :
1174 : /***************************************************************************
1175 : Set the logfile name.
1176 : **************************************************************************/
1177 :
1178 58587 : void debug_set_logfile(const char *name)
1179 : {
1180 58587 : if (name == NULL || *name == 0) {
1181 : /* this copes with calls when smb.conf is not loaded yet */
1182 0 : return;
1183 : }
1184 58587 : TALLOC_FREE(dbgc_config[DBGC_ALL].logfile);
1185 58587 : dbgc_config[DBGC_ALL].logfile = talloc_strdup(NULL, name);
1186 :
1187 58587 : reopen_logs_internal();
1188 : }
1189 :
1190 1526308 : static void debug_close_fd(int fd)
1191 : {
1192 1526308 : if (fd > 2) {
1193 38479 : close(fd);
1194 : }
1195 1526308 : }
1196 :
1197 270 : enum debug_logtype debug_get_log_type(void)
1198 : {
1199 270 : return state.logtype;
1200 : }
1201 :
1202 0 : bool debug_get_output_is_stderr(void)
1203 : {
1204 0 : return (state.logtype == DEBUG_DEFAULT_STDERR) || (state.logtype == DEBUG_STDERR);
1205 : }
1206 :
1207 91 : bool debug_get_output_is_stdout(void)
1208 : {
1209 91 : return (state.logtype == DEBUG_DEFAULT_STDOUT) || (state.logtype == DEBUG_STDOUT);
1210 : }
1211 :
1212 42 : void debug_set_callback(void *private_ptr, debug_callback_fn fn)
1213 : {
1214 42 : debug_init();
1215 42 : if (fn) {
1216 27 : state.logtype = DEBUG_CALLBACK;
1217 27 : state.callback_private = private_ptr;
1218 27 : state.callback = fn;
1219 : } else {
1220 15 : state.logtype = DEBUG_DEFAULT_STDERR;
1221 15 : state.callback_private = NULL;
1222 15 : state.callback = NULL;
1223 : }
1224 42 : }
1225 :
1226 42 : static void debug_callback_log(const char *msg, size_t msg_len, int msg_level)
1227 42 : {
1228 42 : char msg_copy[msg_len];
1229 :
1230 42 : if ((msg_len > 0) && (msg[msg_len-1] == '\n')) {
1231 42 : memcpy(msg_copy, msg, msg_len-1);
1232 42 : msg_copy[msg_len-1] = '\0';
1233 42 : msg = msg_copy;
1234 : }
1235 :
1236 42 : state.callback(state.callback_private, msg_level, msg);
1237 42 : }
1238 :
1239 : /**************************************************************************
1240 : reopen the log files
1241 : note that we now do this unconditionally
1242 : We attempt to open the new debug fp before closing the old. This means
1243 : if we run out of fd's we just keep using the old fd rather than aborting.
1244 : Fix from dgibson@linuxcare.com.
1245 : **************************************************************************/
1246 :
1247 1470687 : static bool reopen_one_log(struct debug_class *config)
1248 : {
1249 1470687 : int old_fd = config->fd;
1250 1470687 : const char *logfile = config->logfile;
1251 : struct stat st;
1252 : int new_fd;
1253 : int ret;
1254 :
1255 1470687 : if (logfile == NULL) {
1256 1431616 : debug_close_fd(old_fd);
1257 1431616 : config->fd = -1;
1258 1431616 : return true;
1259 : }
1260 :
1261 39071 : new_fd = open(logfile, O_WRONLY|O_APPEND|O_CREAT, 0644);
1262 39071 : if (new_fd == -1) {
1263 383 : log_overflow = true;
1264 383 : DBG_ERR("Unable to open new log file '%s': %s\n",
1265 : logfile, strerror(errno));
1266 383 : log_overflow = false;
1267 383 : return false;
1268 : }
1269 :
1270 38688 : debug_close_fd(old_fd);
1271 38688 : smb_set_close_on_exec(new_fd);
1272 38688 : config->fd = new_fd;
1273 :
1274 38688 : ret = fstat(new_fd, &st);
1275 38688 : if (ret != 0) {
1276 0 : log_overflow = true;
1277 0 : DBG_ERR("Unable to fstat() new log file '%s': %s\n",
1278 : logfile, strerror(errno));
1279 0 : log_overflow = false;
1280 0 : return false;
1281 : }
1282 :
1283 38688 : config->ino = st.st_ino;
1284 38688 : return true;
1285 : }
1286 :
1287 : /**
1288 : reopen the log file (usually called because the log file name might have changed)
1289 : */
1290 95087 : bool reopen_logs_internal(void)
1291 : {
1292 95087 : struct debug_backend *b = NULL;
1293 : mode_t oldumask;
1294 : size_t i;
1295 : bool ok;
1296 :
1297 95087 : if (state.reopening_logs) {
1298 0 : return true;
1299 : }
1300 :
1301 : /* Now clear the SIGHUP induced flag */
1302 95087 : state.schedule_reopen_logs = false;
1303 :
1304 95087 : switch (state.logtype) {
1305 12 : case DEBUG_CALLBACK:
1306 12 : return true;
1307 15996 : case DEBUG_STDOUT:
1308 : case DEBUG_DEFAULT_STDOUT:
1309 15996 : debug_close_fd(dbgc_config[DBGC_ALL].fd);
1310 15996 : dbgc_config[DBGC_ALL].fd = 1;
1311 15996 : return true;
1312 :
1313 40008 : case DEBUG_DEFAULT_STDERR:
1314 : case DEBUG_STDERR:
1315 40008 : debug_close_fd(dbgc_config[DBGC_ALL].fd);
1316 40008 : dbgc_config[DBGC_ALL].fd = 2;
1317 40008 : return true;
1318 :
1319 39071 : case DEBUG_FILE:
1320 39071 : b = debug_find_backend("file");
1321 39071 : assert(b != NULL);
1322 :
1323 39071 : b->log_level = MAX_DEBUG_LEVEL;
1324 39071 : break;
1325 : }
1326 :
1327 39071 : oldumask = umask( 022 );
1328 :
1329 39071 : for (i = DBGC_ALL; i < debug_num_classes; i++) {
1330 39071 : if (dbgc_config[i].logfile != NULL) {
1331 39071 : break;
1332 : }
1333 : }
1334 39071 : if (i == debug_num_classes) {
1335 0 : return false;
1336 : }
1337 :
1338 39071 : state.reopening_logs = true;
1339 :
1340 1509375 : for (i = DBGC_ALL; i < debug_num_classes; i++) {
1341 1470687 : ok = reopen_one_log(&dbgc_config[i]);
1342 1470687 : if (!ok) {
1343 383 : break;
1344 : }
1345 : }
1346 :
1347 : /* Fix from klausr@ITAP.Physik.Uni-Stuttgart.De
1348 : * to fix problem where smbd's that generate less
1349 : * than 100 messages keep growing the log.
1350 : */
1351 39071 : force_check_log_size();
1352 39071 : (void)umask(oldumask);
1353 :
1354 : /*
1355 : * If log file was opened or created successfully, take over stderr to
1356 : * catch output into logs.
1357 : */
1358 68678 : if (!state.settings.debug_no_stderr_redirect &&
1359 39071 : dbgc_config[DBGC_ALL].fd > 0) {
1360 39071 : if (dup2(dbgc_config[DBGC_ALL].fd, 2) == -1) {
1361 : /* Close stderr too, if dup2 can't point it -
1362 : at the logfile. There really isn't much
1363 : that can be done on such a fundamental
1364 : failure... */
1365 0 : close_low_fd(2);
1366 : }
1367 : }
1368 :
1369 39071 : state.reopening_logs = false;
1370 :
1371 39071 : return ok;
1372 : }
1373 :
1374 : /**************************************************************************
1375 : Force a check of the log size.
1376 : ***************************************************************************/
1377 :
1378 9498170 : void force_check_log_size( void )
1379 : {
1380 9498170 : debug_count = 100;
1381 9498170 : }
1382 :
1383 0 : _PUBLIC_ void debug_schedule_reopen_logs(void)
1384 : {
1385 0 : state.schedule_reopen_logs = true;
1386 0 : }
1387 :
1388 :
1389 : /***************************************************************************
1390 : Check to see if there is any need to check if the logfile has grown too big.
1391 : **************************************************************************/
1392 :
1393 9446149 : bool need_to_check_log_size(void)
1394 : {
1395 : int maxlog;
1396 : size_t i;
1397 :
1398 9446149 : if (debug_count < 100) {
1399 3415 : return false;
1400 : }
1401 :
1402 9442734 : maxlog = state.settings.max_log_size * 1024;
1403 9442734 : if (maxlog <= 0) {
1404 206 : debug_count = 0;
1405 206 : return false;
1406 : }
1407 :
1408 9442528 : if (dbgc_config[DBGC_ALL].fd > 2) {
1409 1253 : return true;
1410 : }
1411 :
1412 358768450 : for (i = DBGC_ALL + 1; i < debug_num_classes; i++) {
1413 349327175 : if (dbgc_config[i].fd != -1) {
1414 0 : return true;
1415 : }
1416 : }
1417 :
1418 9441275 : debug_count = 0;
1419 9441275 : return false;
1420 : }
1421 :
1422 : /**************************************************************************
1423 : Check to see if the log has grown to be too big.
1424 : **************************************************************************/
1425 :
1426 899 : static void do_one_check_log_size(off_t maxlog, struct debug_class *config)
1427 899 : {
1428 899 : char name[strlen(config->logfile) + 5];
1429 : struct stat st;
1430 : int ret;
1431 899 : bool reopen = false;
1432 : bool ok;
1433 :
1434 899 : if (maxlog == 0) {
1435 899 : return;
1436 : }
1437 :
1438 899 : ret = stat(config->logfile, &st);
1439 899 : if (ret != 0) {
1440 0 : return;
1441 : }
1442 899 : if (st.st_size >= maxlog ) {
1443 0 : reopen = true;
1444 : }
1445 :
1446 899 : if (st.st_ino != config->ino) {
1447 0 : reopen = true;
1448 : }
1449 :
1450 899 : if (!reopen) {
1451 899 : return;
1452 : }
1453 :
1454 : /* reopen_logs_internal() modifies *_fd */
1455 0 : (void)reopen_logs_internal();
1456 :
1457 0 : if (config->fd <= 2) {
1458 0 : return;
1459 : }
1460 0 : ret = fstat(config->fd, &st);
1461 0 : if (ret != 0) {
1462 0 : config->ino = (ino_t)0;
1463 0 : return;
1464 : }
1465 :
1466 0 : config->ino = st.st_ino;
1467 :
1468 0 : if (st.st_size < maxlog) {
1469 0 : return;
1470 : }
1471 :
1472 0 : snprintf(name, sizeof(name), "%s.old", config->logfile);
1473 :
1474 0 : (void)rename(config->logfile, name);
1475 :
1476 0 : ok = reopen_logs_internal();
1477 0 : if (ok) {
1478 0 : return;
1479 : }
1480 : /* We failed to reopen a log - continue using the old name. */
1481 0 : (void)rename(name, config->logfile);
1482 : }
1483 :
1484 899 : static void do_check_log_size(off_t maxlog)
1485 : {
1486 : size_t i;
1487 :
1488 35795 : for (i = DBGC_ALL; i < debug_num_classes; i++) {
1489 34896 : if (dbgc_config[i].fd == -1) {
1490 33997 : continue;
1491 : }
1492 899 : if (dbgc_config[i].logfile == NULL) {
1493 0 : continue;
1494 : }
1495 899 : do_one_check_log_size(maxlog, &dbgc_config[i]);
1496 : }
1497 899 : }
1498 :
1499 3599 : void check_log_size( void )
1500 : {
1501 : off_t maxlog;
1502 :
1503 3599 : if (geteuid() != 0) {
1504 : /*
1505 : * We need to be root to change the log file (tests use a fake
1506 : * geteuid() from third_party/uid_wrapper). Otherwise we skip
1507 : * this and let the main smbd loop or some other process do
1508 : * the work.
1509 : */
1510 14 : return;
1511 : }
1512 :
1513 3585 : if(log_overflow || (!state.schedule_reopen_logs && !need_to_check_log_size())) {
1514 2686 : return;
1515 : }
1516 :
1517 899 : maxlog = state.settings.max_log_size * 1024;
1518 :
1519 899 : if (state.schedule_reopen_logs) {
1520 0 : (void)reopen_logs_internal();
1521 : }
1522 :
1523 899 : do_check_log_size(maxlog);
1524 :
1525 : /*
1526 : * Here's where we need to panic if dbgc_config[DBGC_ALL].fd == 0 or -1
1527 : * (invalid values)
1528 : */
1529 :
1530 899 : if (dbgc_config[DBGC_ALL].fd <= 0) {
1531 : /* This code should only be reached in very strange
1532 : * circumstances. If we merely fail to open the new log we
1533 : * should stick with the old one. ergo this should only be
1534 : * reached when opening the logs for the first time: at
1535 : * startup or when the log level is increased from zero.
1536 : * -dwg 6 June 2000
1537 : */
1538 0 : int fd = open( "/dev/console", O_WRONLY, 0);
1539 0 : if (fd != -1) {
1540 0 : smb_set_close_on_exec(fd);
1541 0 : dbgc_config[DBGC_ALL].fd = fd;
1542 0 : DBG_ERR("check_log_size: open of debug file %s failed "
1543 : "- using console.\n",
1544 : dbgc_config[DBGC_ALL].logfile);
1545 : } else {
1546 : /*
1547 : * We cannot continue without a debug file handle.
1548 : */
1549 0 : abort();
1550 : }
1551 : }
1552 899 : debug_count = 0;
1553 : }
1554 :
1555 : /*************************************************************************
1556 : Write an debug message on the debugfile.
1557 : This is called by format_debug_text().
1558 : ************************************************************************/
1559 :
1560 37599 : static void Debug1(const char *msg, size_t msg_len)
1561 : {
1562 37599 : int old_errno = errno;
1563 :
1564 37599 : debug_count++;
1565 :
1566 37599 : switch(state.logtype) {
1567 42 : case DEBUG_CALLBACK:
1568 42 : debug_callback_log(msg, msg_len, current_msg_level);
1569 42 : break;
1570 34692 : case DEBUG_STDOUT:
1571 : case DEBUG_STDERR:
1572 : case DEBUG_DEFAULT_STDOUT:
1573 : case DEBUG_DEFAULT_STDERR:
1574 34692 : if (dbgc_config[DBGC_ALL].fd > 0) {
1575 : ssize_t ret;
1576 : do {
1577 34692 : ret = write(dbgc_config[DBGC_ALL].fd,
1578 : msg,
1579 : msg_len);
1580 34692 : } while (ret == -1 && errno == EINTR);
1581 : }
1582 34692 : break;
1583 2865 : case DEBUG_FILE:
1584 2865 : debug_backends_log(msg, msg_len, current_msg_level);
1585 2865 : break;
1586 : };
1587 :
1588 37599 : errno = old_errno;
1589 37599 : }
1590 :
1591 : /**************************************************************************
1592 : Print the buffer content via Debug1(), then reset the buffer.
1593 : Input: none
1594 : Output: none
1595 : ****************************************************************************/
1596 :
1597 37564 : static void bufr_print( void )
1598 : {
1599 37564 : format_bufr[format_pos] = '\0';
1600 37564 : (void)Debug1(format_bufr, format_pos);
1601 37564 : format_pos = 0;
1602 37564 : }
1603 :
1604 : /***************************************************************************
1605 : Format the debug message text.
1606 :
1607 : Input: msg - Text to be added to the "current" debug message text.
1608 :
1609 : Output: none.
1610 :
1611 : Notes: The purpose of this is two-fold. First, each call to syslog()
1612 : (used by Debug1(), see above) generates a new line of syslog
1613 : output. This is fixed by storing the partial lines until the
1614 : newline character is encountered. Second, printing the debug
1615 : message lines when a newline is encountered allows us to add
1616 : spaces, thus indenting the body of the message and making it
1617 : more readable.
1618 : **************************************************************************/
1619 :
1620 199982 : static void format_debug_text( const char *msg )
1621 : {
1622 : size_t i;
1623 199982 : bool timestamp = (state.logtype == DEBUG_FILE && (state.settings.timestamp_logs));
1624 :
1625 199982 : debug_init();
1626 :
1627 3041364 : for( i = 0; msg[i]; i++ ) {
1628 : /* Indent two spaces at each new line. */
1629 2841382 : if(timestamp && 0 == format_pos) {
1630 2865 : format_bufr[0] = format_bufr[1] = ' ';
1631 2865 : format_pos = 2;
1632 : }
1633 :
1634 : /* If there's room, copy the character to the format buffer. */
1635 2841382 : if (format_pos < FORMAT_BUFR_SIZE - 1)
1636 2841382 : format_bufr[format_pos++] = msg[i];
1637 :
1638 : /* If a newline is encountered, print & restart. */
1639 2841382 : if( '\n' == msg[i] )
1640 37529 : bufr_print();
1641 :
1642 : /* If the buffer is full dump it out, reset it, and put out a line
1643 : * continuation indicator.
1644 : */
1645 2841382 : if (format_pos >= FORMAT_BUFR_SIZE - 1) {
1646 35 : const char cont[] = " +>\n";
1647 35 : bufr_print();
1648 35 : (void)Debug1(cont , sizeof(cont) - 1);
1649 : }
1650 : }
1651 :
1652 : /* Just to be safe... */
1653 199982 : format_bufr[format_pos] = '\0';
1654 199982 : }
1655 :
1656 : /***************************************************************************
1657 : Flush debug output, including the format buffer content.
1658 :
1659 : Input: none
1660 : Output: none
1661 : ***************************************************************************/
1662 :
1663 0 : void dbgflush( void )
1664 : {
1665 0 : bufr_print();
1666 0 : }
1667 :
1668 199577 : bool dbgsetclass(int level, int cls)
1669 : {
1670 : /* Set current_msg_level. */
1671 199577 : current_msg_level = level;
1672 :
1673 : /* Set current message class */
1674 199577 : current_msg_class = cls;
1675 :
1676 199577 : return true;
1677 : }
1678 :
1679 : /***************************************************************************
1680 : Put a Debug Header into header_str.
1681 :
1682 : Input: level - Debug level of the message (not the system-wide debug
1683 : level. )
1684 : cls - Debuglevel class of the calling module.
1685 : location - Pointer to a string containing the name of the file
1686 : from which this function was called, or an empty string
1687 : if the __FILE__ macro is not implemented.
1688 : func - Pointer to a string containing the name of the function
1689 : from which this function was called, or an empty string
1690 : if the __FUNCTION__ macro is not implemented.
1691 :
1692 : Output: Always true. This makes it easy to fudge a call to dbghdr()
1693 : in a macro, since the function can be called as part of a test.
1694 : Eg: ( (level <= DEBUGLEVEL) && (dbghdr(level,"",line)) )
1695 :
1696 : Notes: This function takes care of setting current_msg_level.
1697 :
1698 : ****************************************************************************/
1699 :
1700 22408 : bool dbghdrclass(int level, int cls, const char *location, const char *func)
1701 : {
1702 : /* Ensure we don't lose any real errno value. */
1703 22408 : int old_errno = errno;
1704 22408 : bool verbose = false;
1705 : struct timeval tv;
1706 : struct timeval_buf tvbuf;
1707 :
1708 : /*
1709 : * This might be overkill, but if another early return is
1710 : * added later then initialising these avoids potential
1711 : * problems
1712 : */
1713 22408 : state.hs_len = 0;
1714 22408 : state.header_str[0] = '\0';
1715 :
1716 22408 : if( format_pos ) {
1717 : /* This is a fudge. If there is stuff sitting in the format_bufr, then
1718 : * the *right* thing to do is to call
1719 : * format_debug_text( "\n" );
1720 : * to write the remainder, and then proceed with the new header.
1721 : * Unfortunately, there are several places in the code at which
1722 : * the DEBUG() macro is used to build partial lines. That in mind,
1723 : * we'll work under the assumption that an incomplete line indicates
1724 : * that a new header is *not* desired.
1725 : */
1726 121 : return( true );
1727 : }
1728 :
1729 22287 : dbgsetclass(level, cls);
1730 :
1731 : /* Don't print a header if we're logging to stdout. */
1732 22287 : if ( state.logtype != DEBUG_FILE ) {
1733 19624 : return( true );
1734 : }
1735 :
1736 : /* Print the header if timestamps are turned on. If parameters are
1737 : * not yet loaded, then default to timestamps on.
1738 : */
1739 2663 : if (!(state.settings.timestamp_logs ||
1740 0 : state.settings.debug_prefix_timestamp ||
1741 0 : state.settings.debug_syslog_format)) {
1742 0 : return true;
1743 : }
1744 :
1745 2663 : GetTimeOfDay(&tv);
1746 :
1747 2663 : if (state.settings.debug_syslog_format) {
1748 0 : if (state.settings.debug_hires_timestamp) {
1749 0 : timeval_str_buf(&tv, true, true, &tvbuf);
1750 : } else {
1751 : time_t t;
1752 : struct tm *tm;
1753 :
1754 0 : t = (time_t)tv.tv_sec;
1755 0 : tm = localtime(&t);
1756 0 : if (tm != NULL) {
1757 : size_t len;
1758 0 : len = strftime(tvbuf.buf,
1759 : sizeof(tvbuf.buf),
1760 : "%b %e %T",
1761 : tm);
1762 0 : if (len == 0) {
1763 : /* Trigger default time format below */
1764 0 : tm = NULL;
1765 : }
1766 : }
1767 0 : if (tm == NULL) {
1768 0 : snprintf(tvbuf.buf,
1769 : sizeof(tvbuf.buf),
1770 : "%ld seconds since the Epoch", (long)t);
1771 : }
1772 : }
1773 :
1774 0 : ensure_hostname();
1775 0 : state.hs_len = snprintf(state.header_str,
1776 : sizeof(state.header_str),
1777 : "%s %.*s %s[%u]: ",
1778 : tvbuf.buf,
1779 : (int)(sizeof(state.hostname) - 1),
1780 : state.hostname,
1781 : state.prog_name,
1782 0 : (unsigned int) getpid());
1783 :
1784 0 : goto full;
1785 : }
1786 :
1787 2663 : timeval_str_buf(&tv, false, state.settings.debug_hires_timestamp,
1788 : &tvbuf);
1789 :
1790 2663 : state.hs_len = snprintf(state.header_str,
1791 : sizeof(state.header_str),
1792 : "[%s, %2d",
1793 : tvbuf.buf,
1794 : level);
1795 2663 : if (state.hs_len >= sizeof(state.header_str) - 1) {
1796 0 : goto full;
1797 : }
1798 :
1799 2663 : if (unlikely(dbgc_config[cls].loglevel >= 10)) {
1800 0 : verbose = true;
1801 : }
1802 :
1803 2663 : if (verbose || state.settings.debug_pid) {
1804 49 : state.hs_len += snprintf(state.header_str + state.hs_len,
1805 31 : sizeof(state.header_str) - state.hs_len,
1806 : ", pid=%u",
1807 31 : (unsigned int)getpid());
1808 31 : if (state.hs_len >= sizeof(state.header_str) - 1) {
1809 0 : goto full;
1810 : }
1811 : }
1812 :
1813 2663 : if (verbose || state.settings.debug_uid) {
1814 0 : state.hs_len += snprintf(state.header_str + state.hs_len,
1815 0 : sizeof(state.header_str) - state.hs_len,
1816 : ", effective(%u, %u), real(%u, %u)",
1817 0 : (unsigned int)geteuid(),
1818 0 : (unsigned int)getegid(),
1819 0 : (unsigned int)getuid(),
1820 0 : (unsigned int)getgid());
1821 0 : if (state.hs_len >= sizeof(state.header_str) - 1) {
1822 0 : goto full;
1823 : }
1824 : }
1825 :
1826 2663 : if ((verbose || state.settings.debug_class)
1827 0 : && (cls != DBGC_ALL)) {
1828 0 : state.hs_len += snprintf(state.header_str + state.hs_len,
1829 0 : sizeof(state.header_str) - state.hs_len,
1830 : ", class=%s",
1831 0 : classname_table[cls]);
1832 0 : if (state.hs_len >= sizeof(state.header_str) - 1) {
1833 0 : goto full;
1834 : }
1835 : }
1836 :
1837 2663 : if (debug_traceid_get() != 0) {
1838 0 : state.hs_len += snprintf(state.header_str + state.hs_len,
1839 0 : sizeof(state.header_str) - state.hs_len,
1840 : ", traceid=%" PRIu64,
1841 : debug_traceid_get());
1842 0 : if (state.hs_len >= sizeof(state.header_str) - 1) {
1843 0 : goto full;
1844 : }
1845 : }
1846 :
1847 2663 : state.header_str[state.hs_len] = ']';
1848 2663 : state.hs_len++;
1849 2663 : if (state.hs_len < sizeof(state.header_str) - 1) {
1850 2663 : state.header_str[state.hs_len] = ' ';
1851 2663 : state.hs_len++;
1852 : }
1853 2663 : state.header_str[state.hs_len] = '\0';
1854 :
1855 2663 : if (!state.settings.debug_prefix_timestamp) {
1856 2663 : state.hs_len += snprintf(state.header_str + state.hs_len,
1857 2663 : sizeof(state.header_str) - state.hs_len,
1858 : "%s(%s)\n",
1859 : location,
1860 : func);
1861 2663 : if (state.hs_len >= sizeof(state.header_str)) {
1862 0 : goto full;
1863 : }
1864 : }
1865 :
1866 5107 : full:
1867 : /*
1868 : * Above code never overflows state.header_str and always
1869 : * NUL-terminates correctly. However, state.hs_len can point
1870 : * past the end of the buffer to indicate that truncation
1871 : * occurred, so fix it if necessary, since state.hs_len is
1872 : * expected to be used after return.
1873 : */
1874 2663 : if (state.hs_len >= sizeof(state.header_str)) {
1875 0 : state.hs_len = sizeof(state.header_str) - 1;
1876 : }
1877 :
1878 2663 : state.header_str_no_nl[0] = '\0';
1879 :
1880 2663 : errno = old_errno;
1881 2663 : return( true );
1882 : }
1883 :
1884 : /***************************************************************************
1885 : Add text to the body of the "current" debug message via the format buffer.
1886 :
1887 : Input: format_str - Format string, as used in printf(), et. al.
1888 : ... - Variable argument list.
1889 :
1890 : ..or.. va_alist - Old style variable parameter list starting point.
1891 :
1892 : Output: Always true. See dbghdr() for more info, though this is not
1893 : likely to be used in the same way.
1894 :
1895 : ***************************************************************************/
1896 :
1897 : static inline bool __dbgtext_va(const char *format_str, va_list ap) PRINTF_ATTRIBUTE(1,0);
1898 199982 : static inline bool __dbgtext_va(const char *format_str, va_list ap)
1899 : {
1900 199982 : char *msgbuf = NULL;
1901 199982 : bool ret = true;
1902 : int res;
1903 :
1904 199982 : res = vasprintf(&msgbuf, format_str, ap);
1905 199982 : if (res != -1) {
1906 199982 : format_debug_text(msgbuf);
1907 : } else {
1908 0 : ret = false;
1909 : }
1910 199982 : SAFE_FREE(msgbuf);
1911 199982 : return ret;
1912 : }
1913 :
1914 0 : bool dbgtext_va(const char *format_str, va_list ap)
1915 : {
1916 0 : return __dbgtext_va(format_str, ap);
1917 : }
1918 :
1919 199982 : bool dbgtext(const char *format_str, ... )
1920 : {
1921 : va_list ap;
1922 : bool ret;
1923 :
1924 199982 : va_start(ap, format_str);
1925 199982 : ret = __dbgtext_va(format_str, ap);
1926 199982 : va_end(ap);
1927 :
1928 199982 : return ret;
1929 : }
1930 :
1931 : static uint64_t debug_traceid = 0;
1932 :
1933 0 : uint64_t debug_traceid_set(uint64_t id)
1934 : {
1935 0 : uint64_t old_id = debug_traceid;
1936 0 : debug_traceid = id;
1937 0 : return old_id;
1938 : }
1939 :
1940 92661 : uint64_t debug_traceid_get(void)
1941 : {
1942 92661 : return debug_traceid;
1943 : }
|
