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