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