/src/freeradius-server/src/lib/util/log.c
Line | Count | Source (jump to first uncovered line) |
1 | | /* |
2 | | * This library is free software; you can redistribute it and/or |
3 | | * modify it under the terms of the GNU Lesser General Public |
4 | | * License as published by the Free Software Foundation; either |
5 | | * version 2.1 of the License, or (at your option) any later version. |
6 | | * |
7 | | * This library is distributed in the hope that it will be useful, |
8 | | * but WITHOUT ANY WARRANTY; without even the implied warranty of |
9 | | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU |
10 | | * Lesser General Public License for more details. |
11 | | * |
12 | | * You should have received a copy of the GNU Lesser General Public |
13 | | * License along with this library; if not, write to the Free Software |
14 | | * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA |
15 | | */ |
16 | | |
17 | | /** Support functions for logging in FreeRADIUS libraries |
18 | | * |
19 | | * @file src/lib/util/log.c |
20 | | * |
21 | | * @copyright 2003,2006 The FreeRADIUS server project |
22 | | */ |
23 | | RCSID("$Id: 2598af93dce4cfbff3992fa0f0b25a99eac9497e $") |
24 | | |
25 | | #include <freeradius-devel/util/debug.h> |
26 | | #include <freeradius-devel/util/log.h> |
27 | | #include <freeradius-devel/util/print.h> |
28 | | #include <freeradius-devel/util/sbuff.h> |
29 | | #include <freeradius-devel/util/syserror.h> |
30 | | #include <freeradius-devel/util/atexit.h> |
31 | | #include <freeradius-devel/util/value.h> |
32 | | #include <freeradius-devel/util/time.h> |
33 | | |
34 | | #include <fcntl.h> |
35 | | #ifdef HAVE_FEATURES_H |
36 | | # include <features.h> |
37 | | #endif |
38 | | #ifdef HAVE_SYSLOG_H |
39 | | # include <syslog.h> |
40 | | #endif |
41 | | |
42 | | FILE *fr_log_fp = NULL; |
43 | | int fr_debug_lvl = 0; |
44 | | |
45 | | static _Thread_local TALLOC_CTX *fr_log_pool; |
46 | | |
47 | | static uint32_t location_indent = 30; |
48 | | static fr_event_list_t *log_el; //!< Event loop we use for process logging data. |
49 | | |
50 | | static int stderr_fd = -1; //!< The original unmolested stderr file descriptor |
51 | | static int stdout_fd = -1; //!< The original unmolested stdout file descriptor |
52 | | |
53 | | static fr_log_fd_event_ctx_t stdout_ctx; //!< Logging ctx for stdout. |
54 | | static fr_log_fd_event_ctx_t stderr_ctx; //!< Logging ctx for stderr. |
55 | | |
56 | | static int stdout_pipe[2]; //!< Pipe we use to transport stdout data. |
57 | | static int stderr_pipe[2]; //!< Pipe we use to transport stderr data. |
58 | | |
59 | | static FILE *devnull; //!< File handle for /dev/null |
60 | | |
61 | | bool fr_log_rate_limit = true; //!< Whether repeated log entries should be rate limited |
62 | | |
63 | | static _Thread_local fr_log_type_t log_msg_type;//!< The type of the last message logged. |
64 | | ///< Mainly uses for syslog. |
65 | | |
66 | | /** Canonicalize error strings, removing tabs, and generate spaces for error marker |
67 | | * |
68 | | * @note talloc_free must be called on the buffer returned in spaces and text |
69 | | * |
70 | | * Used to produce error messages such as this: |
71 | | @verbatim |
72 | | I'm a string with a parser # error |
73 | | ^ Unexpected character in string |
74 | | @endverbatim |
75 | | * |
76 | | * With code resembling this: |
77 | | @code{.c} |
78 | | ERROR("%s", parsed_str); |
79 | | ERROR("%s^ %s", space, text); |
80 | | @endcode |
81 | | * |
82 | | * @todo merge with above function (log_request_marker) |
83 | | * |
84 | | * @param sp Where to write a dynamically allocated buffer of spaces used to indent the error text. |
85 | | * @param text Where to write the canonicalized version of fmt (the error text). |
86 | | * @param ctx to allocate the spaces and text buffers in. |
87 | | * @param slen of error marker. Expects negative integer value, as returned by parse functions. |
88 | | * @param fmt to canonicalize. |
89 | | */ |
90 | | void fr_canonicalize_error(TALLOC_CTX *ctx, char **sp, char **text, ssize_t slen, char const *fmt) |
91 | 0 | { |
92 | 0 | size_t offset, prefix, suffix; |
93 | 0 | char *spaces, *p; |
94 | 0 | char const *start; |
95 | 0 | char *value; |
96 | 0 | size_t inlen; |
97 | |
|
98 | 0 | offset = -slen; |
99 | |
|
100 | 0 | inlen = strlen(fmt); |
101 | 0 | start = fmt; |
102 | 0 | prefix = suffix = 0; |
103 | | |
104 | | /* |
105 | | * Catch bad callers. |
106 | | */ |
107 | 0 | if (offset > inlen) { |
108 | 0 | *sp = talloc_strdup(ctx, ""); |
109 | 0 | *text = talloc_strdup(ctx, ""); |
110 | 0 | return; |
111 | 0 | } |
112 | | |
113 | | /* |
114 | | * Too many characters before the inflection point. Skip |
115 | | * leading text until we have only 45 characters before it. |
116 | | */ |
117 | 0 | if (offset > 30) { |
118 | 0 | size_t skip = offset - 30; |
119 | |
|
120 | 0 | start += skip; |
121 | 0 | inlen -= skip; |
122 | 0 | offset -= skip; |
123 | 0 | prefix = 4; |
124 | 0 | } |
125 | | |
126 | | /* |
127 | | * Too many characters after the inflection point, |
128 | | * truncate it to 30 characters after the inflection |
129 | | * point. |
130 | | */ |
131 | 0 | if (inlen > (offset + 30)) { |
132 | 0 | inlen = offset + 30; |
133 | 0 | suffix = 4; |
134 | 0 | } |
135 | | |
136 | | /* |
137 | | * Allocate an array to hold just the text we need. |
138 | | */ |
139 | 0 | value = talloc_array(ctx, char, prefix + inlen + 1 + suffix); |
140 | 0 | if (prefix) { |
141 | 0 | memcpy(value, "... ", 4); |
142 | 0 | } |
143 | 0 | memcpy(value + prefix, start, inlen); |
144 | 0 | if (suffix) { |
145 | 0 | memcpy(value + prefix + inlen, "...", 3); |
146 | 0 | value[prefix + inlen + 3] = '\0'; |
147 | 0 | } |
148 | 0 | value[prefix + inlen + suffix] = '\0'; |
149 | | |
150 | | /* |
151 | | * Smash tabs to spaces for the input string. |
152 | | */ |
153 | 0 | for (p = value; *p != '\0'; p++) { |
154 | 0 | if (*p == '\t') *p = ' '; |
155 | 0 | } |
156 | | |
157 | | /* |
158 | | * Allocate the spaces array |
159 | | */ |
160 | 0 | spaces = talloc_array(ctx, char, prefix + offset + 1); |
161 | 0 | memset(spaces, ' ', prefix + offset); |
162 | 0 | spaces[prefix + offset] = '\0'; |
163 | |
|
164 | 0 | *sp = spaces; |
165 | 0 | *text = value; |
166 | 0 | } |
167 | | |
168 | | /** Function to provide as the readable callback to the event loop |
169 | | * |
170 | | * Writes any data read from a file descriptor to the request log, |
171 | | * tries very hard not to chop lines in the middle, but will split |
172 | | * at 1024 byte boundaries if forced to. |
173 | | * |
174 | | * @param[in] el UNUSED |
175 | | * @param[in] fd UNUSED |
176 | | * @param[in] flags UNUSED |
177 | | * @param[in] uctx Pointer to a log_fd_event_ctx_t |
178 | | */ |
179 | | void fr_log_fd_event(UNUSED fr_event_list_t *el, int fd, UNUSED int flags, void *uctx) |
180 | 0 | { |
181 | 0 | char buffer[1024]; |
182 | 0 | fr_log_fd_event_ctx_t *log_info = uctx; |
183 | 0 | fr_sbuff_t sbuff; |
184 | 0 | fr_sbuff_marker_t m_start, m_end; |
185 | |
|
186 | 0 | fr_sbuff_term_t const line_endings = FR_SBUFF_TERMS(L("\n"), L("\r")); |
187 | |
|
188 | 0 | if (log_info->lvl < fr_debug_lvl) { |
189 | 0 | while (read(fd, buffer, sizeof(buffer)) > 0); |
190 | 0 | return; |
191 | 0 | } |
192 | | |
193 | 0 | fr_sbuff_init_out(&sbuff, buffer, sizeof(buffer)); |
194 | 0 | fr_sbuff_marker(&m_start, &sbuff); |
195 | 0 | fr_sbuff_marker(&m_end, &sbuff); |
196 | |
|
197 | 0 | #ifndef NDEBUG |
198 | 0 | memset(buffer, 0x42, sizeof(buffer)); |
199 | 0 | #endif |
200 | |
|
201 | 0 | for (;;) { |
202 | 0 | ssize_t slen; |
203 | |
|
204 | 0 | slen = read(fd, fr_sbuff_current(&m_end), fr_sbuff_remaining(&m_end)); |
205 | 0 | if ((slen < 0) && (errno == EINTR)) continue; |
206 | | |
207 | 0 | if (slen > 0) fr_sbuff_advance(&m_end, slen); |
208 | |
|
209 | 0 | while (fr_sbuff_ahead(&m_end) > 0) { |
210 | 0 | fr_sbuff_adv_until(&sbuff, fr_sbuff_ahead(&m_end), &line_endings, '\0'); |
211 | | |
212 | | /* |
213 | | * Incomplete line, try and read the rest. |
214 | | */ |
215 | 0 | if ((slen > 0) && (fr_sbuff_used(&m_start) > 0) && |
216 | 0 | !fr_sbuff_is_terminal(&sbuff, &line_endings)) { |
217 | 0 | break; |
218 | 0 | } |
219 | | |
220 | 0 | fr_log(log_info->dst, log_info->type, |
221 | 0 | __FILE__, __LINE__, |
222 | 0 | "%s%s%pV", |
223 | 0 | log_info->prefix ? log_info->prefix : "", |
224 | 0 | log_info->prefix ? " - " : "", |
225 | 0 | fr_box_strvalue_len(fr_sbuff_current(&m_start), fr_sbuff_behind(&m_start))); |
226 | |
|
227 | 0 | fr_sbuff_advance(&sbuff, 1); /* Skip the whitespace */ |
228 | 0 | fr_sbuff_set(&m_start, &sbuff); |
229 | 0 | } |
230 | | |
231 | | /* |
232 | | * Error or done |
233 | | */ |
234 | 0 | if (slen <= 0) break; |
235 | | |
236 | | /* |
237 | | * Clear out the existing data |
238 | | */ |
239 | 0 | fr_sbuff_shift(&sbuff, fr_sbuff_used(&m_start)); |
240 | 0 | } |
241 | 0 | } |
242 | | |
243 | | /** Maps log categories to message prefixes |
244 | | */ |
245 | | fr_table_num_ordered_t const fr_log_levels[] = { |
246 | | { L("Debug : "), L_DBG }, |
247 | | { L("Info : "), L_INFO }, |
248 | | { L("Warn : "), L_WARN }, |
249 | | { L("Error : "), L_ERR }, |
250 | | { L("Auth : "), L_AUTH }, |
251 | | { L("INFO : "), L_DBG_INFO }, |
252 | | { L("WARN : "), L_DBG_WARN }, |
253 | | { L("ERROR : "), L_DBG_ERR }, |
254 | | { L("WARN : "), L_DBG_WARN_REQ }, |
255 | | { L("ERROR : "), L_DBG_ERR_REQ } |
256 | | }; |
257 | | size_t fr_log_levels_len = NUM_ELEMENTS(fr_log_levels); |
258 | | |
259 | | /** @name VT100 escape sequences |
260 | | * |
261 | | * These sequences may be written to VT100 terminals to change the |
262 | | * colour and style of the text. |
263 | | * |
264 | | @code{.c} |
265 | | fprintf(stdout, VTC_RED "This text will be coloured red" VTC_RESET); |
266 | | @endcode |
267 | | * @{ |
268 | | */ |
269 | | #define VTC_RED "\x1b[31m" //!< Colour following text red. |
270 | | #define VTC_YELLOW "\x1b[33m" //!< Colour following text yellow. |
271 | | #define VTC_BOLD "\x1b[1m" //!< Embolden following text. |
272 | 0 | #define VTC_RESET "\x1b[0m" //!< Reset terminal text to default style/colour. |
273 | | /** @} */ |
274 | | |
275 | | /** Maps log categories to VT100 style/colour escape sequences |
276 | | */ |
277 | | static fr_table_num_ordered_t const colours[] = { |
278 | | { L(VTC_BOLD), L_INFO }, |
279 | | { L(VTC_RED), L_ERR }, |
280 | | { L(VTC_BOLD VTC_YELLOW), L_WARN }, |
281 | | { L(VTC_BOLD VTC_RED), L_DBG_ERR }, |
282 | | { L(VTC_BOLD VTC_YELLOW), L_DBG_WARN }, |
283 | | { L(VTC_BOLD VTC_RED), L_DBG_ERR_REQ }, |
284 | | { L(VTC_BOLD VTC_YELLOW), L_DBG_WARN_REQ }, |
285 | | }; |
286 | | static size_t colours_len = NUM_ELEMENTS(colours); |
287 | | |
288 | | |
289 | | bool log_dates_utc = false; |
290 | | |
291 | | fr_log_t default_log = { |
292 | | .colourise = false, //!< Will be set later. Should be off before we do terminal detection. |
293 | | .fd = STDOUT_FILENO, |
294 | | .dst = L_DST_STDOUT, |
295 | | .file = NULL, |
296 | | .timestamp = L_TIMESTAMP_AUTO |
297 | | }; |
298 | | |
299 | | /** Cleanup the memory pool used by vlog_request |
300 | | * |
301 | | */ |
302 | | static int _fr_log_pool_free(void *arg) |
303 | 0 | { |
304 | 0 | if (talloc_free(arg) < 0) return -1; |
305 | 0 | fr_log_pool = NULL; |
306 | 0 | return 0; |
307 | 0 | } |
308 | | |
309 | | /** talloc ctx to use when composing log messages |
310 | | * |
311 | | * Functions must ensure that they allocate a new ctx from the one returned |
312 | | * here, and that this ctx is freed before the function returns. |
313 | | * |
314 | | * @return talloc pool to use for scratch space. |
315 | | */ |
316 | | TALLOC_CTX *fr_log_pool_init(void) |
317 | 0 | { |
318 | 0 | TALLOC_CTX *pool; |
319 | |
|
320 | 0 | pool = fr_log_pool; |
321 | 0 | if (unlikely(!pool)) { |
322 | 0 | if (fr_atexit_is_exiting()) return NULL; /* No new pools if we're exiting */ |
323 | | |
324 | 0 | pool = talloc_pool(NULL, 16384); |
325 | 0 | if (!pool) { |
326 | 0 | fr_perror("Failed allocating memory for vlog_request_pool"); |
327 | 0 | return NULL; |
328 | 0 | } |
329 | 0 | fr_atexit_thread_local(fr_log_pool, _fr_log_pool_free, pool); |
330 | 0 | } |
331 | | |
332 | 0 | return pool; |
333 | 0 | } |
334 | | |
335 | | /** Send a server log message to its destination |
336 | | * |
337 | | * @param[in] log destination. |
338 | | * @param[in] type of log message. |
339 | | * @param[in] file src file the log message was generated in. |
340 | | * @param[in] line number the log message was generated on. |
341 | | * @param[in] fmt with printf style substitution tokens. |
342 | | * @param[in] ap Substitution arguments. |
343 | | */ |
344 | | void fr_vlog(fr_log_t const *log, fr_log_type_t type, char const *file, int line, char const *fmt, va_list ap) |
345 | 0 | { |
346 | 0 | int colourise = log->colourise; |
347 | 0 | char *buffer; |
348 | 0 | TALLOC_CTX *pool, *thread_log_pool; |
349 | 0 | char const *fmt_colour = ""; |
350 | 0 | char const *fmt_location = ""; |
351 | 0 | char fmt_time[50]; |
352 | 0 | char const *fmt_facility = ""; |
353 | 0 | char const *fmt_type = ""; |
354 | 0 | char *fmt_msg; |
355 | |
|
356 | 0 | static char const *spaces = " "; /* 40 */ |
357 | |
|
358 | 0 | fmt_time[0] = '\0'; |
359 | | |
360 | | /* |
361 | | * If we don't want any messages, then |
362 | | * throw them away. |
363 | | */ |
364 | 0 | if (log->dst == L_DST_NULL) return; |
365 | | |
366 | 0 | thread_log_pool = fr_log_pool_init(); |
367 | 0 | pool = talloc_new(thread_log_pool); /* Track our local allocations */ |
368 | | |
369 | | /* |
370 | | * Set colourisation |
371 | | */ |
372 | 0 | if (colourise) { |
373 | 0 | fmt_colour = fr_table_str_by_value(colours, type, NULL); |
374 | 0 | if (!fmt_colour) colourise = false; |
375 | 0 | } |
376 | | |
377 | | /* |
378 | | * Print src file/line |
379 | | */ |
380 | 0 | if (log->line_number) { |
381 | 0 | size_t len; |
382 | 0 | int pad = 0; |
383 | 0 | char *str; |
384 | |
|
385 | 0 | str = talloc_asprintf(pool, "%s:%i", file, line); |
386 | 0 | len = talloc_array_length(str) - 1; |
387 | | |
388 | | /* |
389 | | * Only increase the indent |
390 | | */ |
391 | 0 | if (len > location_indent) { |
392 | 0 | location_indent = len; |
393 | 0 | } else { |
394 | 0 | pad = location_indent - len; |
395 | 0 | } |
396 | |
|
397 | 0 | fmt_location = talloc_asprintf_append_buffer(str, "%.*s : ", pad, spaces); |
398 | 0 | } |
399 | | /* |
400 | | * Determine if we need to add a timestamp to the start of the message |
401 | | */ |
402 | 0 | switch (log->timestamp) { |
403 | 0 | case L_TIMESTAMP_OFF: |
404 | 0 | break; |
405 | | |
406 | | /* |
407 | | * If we're not logging to syslog, and the debug level is -xxx |
408 | | * then log timestamps by default. |
409 | | */ |
410 | 0 | case L_TIMESTAMP_AUTO: |
411 | 0 | if (log->dst == L_DST_SYSLOG) break; |
412 | 0 | if ((log->dst != L_DST_FILES) && (fr_debug_lvl <= L_DBG_LVL_2)) break; |
413 | 0 | FALL_THROUGH; |
414 | | |
415 | 0 | case L_TIMESTAMP_ON: |
416 | 0 | { |
417 | 0 | fr_unix_time_t now = fr_time_to_unix_time(fr_time()); |
418 | 0 | fr_sbuff_t time_sbuff = FR_SBUFF_OUT(fmt_time, sizeof(fmt_time)); |
419 | 0 | fr_unix_time_to_str(&time_sbuff, now, FR_TIME_RES_USEC, log->dates_utc); |
420 | 0 | break; |
421 | 0 | } |
422 | 0 | } |
423 | | |
424 | | /* |
425 | | * Add ERROR or WARNING prefixes to messages not going to |
426 | | * syslog. It's redundant for syslog because of syslog |
427 | | * facilities. |
428 | | */ |
429 | 0 | if (log->dst != L_DST_SYSLOG) { |
430 | | /* |
431 | | * Only print the 'facility' if we're not colourising the log messages |
432 | | * and this isn't syslog. |
433 | | */ |
434 | 0 | if (!log->colourise && log->print_level) fmt_facility = fr_table_str_by_value(fr_log_levels, type, ": "); |
435 | | |
436 | | /* |
437 | | * Add an additional prefix to highlight that this is a bad message |
438 | | * the user should pay attention to. |
439 | | */ |
440 | 0 | switch (type) { |
441 | 0 | case L_DBG_WARN: |
442 | 0 | case L_DBG_ERR: |
443 | 0 | fmt_type = fr_table_str_by_value(fr_log_levels, type, NULL); |
444 | 0 | break; |
445 | | |
446 | 0 | default: |
447 | 0 | break; |
448 | 0 | } |
449 | 0 | } |
450 | | |
451 | | /* |
452 | | * Sanitize output. |
453 | | * |
454 | | * Most strings should be escaped before they get here. |
455 | | */ |
456 | 0 | { |
457 | 0 | char *p, *end; |
458 | |
|
459 | 0 | p = fmt_msg = fr_vasprintf(pool, fmt, ap); |
460 | 0 | end = p + talloc_array_length(fmt_msg) - 1; |
461 | | |
462 | | /* |
463 | | * Filter out control chars and non UTF8 chars |
464 | | */ |
465 | 0 | for (p = fmt_msg; p < end; p++) { |
466 | 0 | int clen; |
467 | |
|
468 | 0 | switch (*p) { |
469 | 0 | case '\r': |
470 | 0 | case '\n': |
471 | 0 | *p = ' '; |
472 | 0 | break; |
473 | | |
474 | 0 | case '\t': |
475 | 0 | continue; |
476 | | |
477 | 0 | default: |
478 | 0 | clen = fr_utf8_char((uint8_t *)p, -1); |
479 | 0 | if (!clen) { |
480 | 0 | *p = '?'; |
481 | 0 | continue; |
482 | 0 | } |
483 | 0 | p += (clen - 1); |
484 | 0 | break; |
485 | 0 | } |
486 | 0 | } |
487 | 0 | } |
488 | | |
489 | 0 | switch (log->dst) { |
490 | | |
491 | 0 | #ifdef HAVE_SYSLOG_H |
492 | 0 | case L_DST_SYSLOG: |
493 | 0 | { |
494 | 0 | int syslog_priority = L_DBG; |
495 | |
|
496 | 0 | switch (type) { |
497 | 0 | case L_DBG: |
498 | 0 | case L_DBG_INFO: |
499 | 0 | case L_DBG_WARN: |
500 | 0 | case L_DBG_ERR: |
501 | 0 | case L_DBG_ERR_REQ: |
502 | 0 | case L_DBG_WARN_REQ: |
503 | 0 | syslog_priority= LOG_DEBUG; |
504 | 0 | break; |
505 | | |
506 | 0 | case L_INFO: |
507 | 0 | syslog_priority = LOG_INFO; |
508 | 0 | break; |
509 | | |
510 | 0 | case L_WARN: |
511 | 0 | syslog_priority = LOG_WARNING; |
512 | 0 | break; |
513 | | |
514 | 0 | case L_ERR: |
515 | 0 | syslog_priority = LOG_ERR; |
516 | 0 | break; |
517 | | |
518 | 0 | case L_AUTH: |
519 | 0 | syslog_priority = LOG_AUTH | LOG_INFO; |
520 | 0 | break; |
521 | 0 | } |
522 | 0 | syslog(syslog_priority, |
523 | 0 | "%s" /* time */ |
524 | 0 | "%s" /* time sep */ |
525 | 0 | "%s", /* message */ |
526 | 0 | fmt_time, |
527 | 0 | fmt_time[0] ? ": " : "", |
528 | 0 | fmt_msg); |
529 | 0 | } |
530 | 0 | break; |
531 | 0 | #endif |
532 | | |
533 | 0 | case L_DST_FILES: |
534 | 0 | case L_DST_STDOUT: |
535 | 0 | case L_DST_STDERR: |
536 | 0 | { |
537 | 0 | size_t len, wrote; |
538 | |
|
539 | 0 | buffer = talloc_asprintf(pool, |
540 | 0 | "%s" /* colourise */ |
541 | 0 | "%s" /* location */ |
542 | 0 | "%s" /* time */ |
543 | 0 | "%s" /* time sep */ |
544 | 0 | "%s" /* facility */ |
545 | 0 | "%s" /* message type */ |
546 | 0 | "%s" /* message */ |
547 | 0 | "%s" /* colourise reset */ |
548 | 0 | "\n", |
549 | 0 | colourise ? fmt_colour : "", |
550 | 0 | fmt_location, |
551 | 0 | fmt_time, |
552 | 0 | fmt_time[0] ? ": " : "", |
553 | 0 | fmt_facility, |
554 | 0 | fmt_type, |
555 | 0 | fmt_msg, |
556 | 0 | colourise ? VTC_RESET : ""); |
557 | |
|
558 | 0 | len = talloc_array_length(buffer) - 1; |
559 | 0 | wrote = write(log->fd, buffer, len); |
560 | 0 | if (wrote < len) return; |
561 | 0 | } |
562 | 0 | break; |
563 | | |
564 | 0 | default: |
565 | 0 | case L_DST_NULL: /* should have been caught above */ |
566 | 0 | break; |
567 | 0 | } |
568 | | |
569 | 0 | talloc_free(pool); /* clears all temporary allocations */ |
570 | |
|
571 | 0 | return; |
572 | 0 | } |
573 | | |
574 | | /** Send a server log message to its destination |
575 | | * |
576 | | * @param log destination. |
577 | | * @param type of log message. |
578 | | * @param file where the log message originated |
579 | | * @param line where the log message originated |
580 | | * @param fmt with printf style substitution tokens. |
581 | | * @param ... Substitution arguments. |
582 | | */ |
583 | | void fr_log(fr_log_t const *log, fr_log_type_t type, char const *file, int line, char const *fmt, ...) |
584 | 0 | { |
585 | 0 | va_list ap; |
586 | | |
587 | | /* |
588 | | * Non-debug message, or debugging is enabled. Log it. |
589 | | */ |
590 | 0 | if (!(((type & L_DBG) == 0) || (fr_debug_lvl > 0))) return; |
591 | | |
592 | 0 | va_start(ap, fmt); |
593 | 0 | fr_vlog(log, type, file, line, fmt, ap); |
594 | 0 | va_end(ap); |
595 | 0 | } |
596 | | |
597 | | /** Drain any outstanding messages from the fr_strerror buffers |
598 | | * |
599 | | * This function drains any messages from fr_strerror buffer prefixing |
600 | | * the first message with fmt + args. |
601 | | * |
602 | | * If a prefix is specified in rules, this is prepended to all lines |
603 | | * logged. The prefix is useful for adding context, i.e. configuration |
604 | | * file and line number information. |
605 | | * |
606 | | * @param[in] log destination. |
607 | | * @param[in] type of log message. |
608 | | * @param[in] file src file the log message was generated in. |
609 | | * @param[in] line number the log message was generated on. |
610 | | * @param[in] f_rules for printing multiline errors. |
611 | | * @param[in] fmt with printf style substitution tokens. |
612 | | * @param[in] ap Substitution arguments. |
613 | | */ |
614 | | void fr_vlog_perror(fr_log_t const *log, fr_log_type_t type, char const *file, int line, |
615 | | fr_log_perror_format_t const *f_rules, char const *fmt, va_list ap) |
616 | 0 | { |
617 | 0 | char const *error; |
618 | 0 | static fr_log_perror_format_t default_f_rules; |
619 | |
|
620 | 0 | TALLOC_CTX *thread_log_pool; |
621 | 0 | fr_sbuff_marker_t prefix_m; |
622 | |
|
623 | 0 | fr_sbuff_t sbuff; |
624 | 0 | fr_sbuff_uctx_talloc_t tctx; |
625 | | |
626 | | /* |
627 | | * Non-debug message, or debugging is enabled. Log it. |
628 | | */ |
629 | 0 | if (!(((type & L_DBG) == 0) || (fr_debug_lvl > 0))) return; |
630 | | |
631 | 0 | if (!f_rules) f_rules = &default_f_rules; |
632 | |
|
633 | 0 | thread_log_pool = fr_log_pool_init(); |
634 | | |
635 | | /* |
636 | | * Setup the aggregation buffer |
637 | | */ |
638 | 0 | fr_sbuff_init_talloc(thread_log_pool, &sbuff, &tctx, 1024, 16384); |
639 | | |
640 | | /* |
641 | | * Add the prefix for the first line |
642 | | */ |
643 | 0 | if (f_rules->first_prefix) (void) fr_sbuff_in_strcpy(&sbuff, f_rules->first_prefix); |
644 | | |
645 | | /* |
646 | | * Add the (optional) message, and/or (optional) error |
647 | | * with the error_sep. |
648 | | * i.e. <msg>: <error> |
649 | | */ |
650 | 0 | error = fr_strerror_pop(); |
651 | |
|
652 | 0 | if (!error && !fmt) return; /* NOOP */ |
653 | | |
654 | 0 | if (fmt) { |
655 | 0 | va_list aq; |
656 | |
|
657 | 0 | va_copy(aq, ap); |
658 | 0 | fr_sbuff_in_vsprintf(&sbuff, fmt, aq); |
659 | 0 | va_end(aq); |
660 | 0 | } |
661 | |
|
662 | 0 | if (error && (fmt || f_rules->first_prefix)) { |
663 | 0 | if (fmt) (void) fr_sbuff_in_strcpy(&sbuff, ": "); |
664 | 0 | (void) fr_sbuff_in_strcpy(&sbuff, error); |
665 | 0 | } |
666 | |
|
667 | 0 | error = fr_sbuff_start(&sbuff); /* may not be talloced with const */ |
668 | | |
669 | | /* |
670 | | * Log the first line |
671 | | */ |
672 | 0 | fr_log(log, type, file, line, "%s", error); |
673 | |
|
674 | 0 | fr_sbuff_set_to_start(&sbuff); |
675 | 0 | if (f_rules->subsq_prefix) { |
676 | 0 | (void) fr_sbuff_in_strcpy(&sbuff, f_rules->subsq_prefix); |
677 | 0 | fr_sbuff_marker(&prefix_m, &sbuff); |
678 | 0 | } |
679 | | |
680 | | /* |
681 | | * Print out additional error lines |
682 | | */ |
683 | 0 | while ((error = fr_strerror_pop())) { |
684 | 0 | if (f_rules->subsq_prefix) { |
685 | 0 | fr_sbuff_set(&sbuff, &prefix_m); |
686 | 0 | (void) fr_sbuff_in_strcpy(&sbuff, error); /* may not be talloced with const */ |
687 | 0 | error = fr_sbuff_start(&sbuff); |
688 | 0 | } |
689 | |
|
690 | 0 | fr_log(log, type, file, line, "%s", error); |
691 | 0 | } |
692 | |
|
693 | 0 | talloc_free(sbuff.buff); |
694 | 0 | } |
695 | | |
696 | | /** Drain any outstanding messages from the fr_strerror buffers |
697 | | * |
698 | | * This function drains any messages from fr_strerror buffer adding a prefix (fmt) |
699 | | * to the first message. |
700 | | * |
701 | | * @param[in] log destination. |
702 | | * @param[in] type of log message. |
703 | | * @param[in] file src file the log message was generated in. |
704 | | * @param[in] line number the log message was generated on. |
705 | | * @param[in] rules for printing multiline errors. |
706 | | * @param[in] fmt with printf style substitution tokens. |
707 | | * @param[in] ... Substitution arguments. |
708 | | */ |
709 | | void fr_log_perror(fr_log_t const *log, fr_log_type_t type, char const *file, int line, |
710 | | fr_log_perror_format_t const *rules, char const *fmt, ...) |
711 | 0 | { |
712 | 0 | va_list ap; |
713 | |
|
714 | 0 | va_start(ap, fmt); |
715 | 0 | fr_vlog_perror(log, type, file, line, rules, fmt, ap); |
716 | 0 | va_end(ap); |
717 | 0 | } |
718 | | |
719 | | DIAG_OFF(format-nonliteral) |
720 | | /** Print out an error marker |
721 | | * |
722 | | * @param[in] log destination. |
723 | | * @param[in] type of log message. |
724 | | * @param[in] file src file the log message was generated in. |
725 | | * @param[in] line number the log message was generated on. |
726 | | * @param[in] str Subject string we're printing a marker for. |
727 | | * @param[in] str_len Subject string length. Use SIZE_MAX for the |
728 | | * length of the string. |
729 | | * @param[in] marker_idx Where to place the marker. May be negative. |
730 | | * @param[in] marker text to print at marker_idx. |
731 | | * @param[in] line_prefix_fmt Prefix to add to the marker messages. |
732 | | * @param[in] ... Arguments for line_prefix_fmt. |
733 | | */ |
734 | | void fr_log_marker(fr_log_t const *log, fr_log_type_t type, char const *file, int line, |
735 | | char const *str, size_t str_len, |
736 | | ssize_t marker_idx, char const *marker, char const *line_prefix_fmt, ...) |
737 | 0 | { |
738 | 0 | char const *ellipses = ""; |
739 | 0 | va_list ap; |
740 | 0 | TALLOC_CTX *thread_log_pool = fr_log_pool_init(); |
741 | 0 | char *line_prefix = NULL; |
742 | 0 | static char const marker_spaces[] = " "; /* 60 */ |
743 | |
|
744 | 0 | if (str_len == SIZE_MAX) str_len = strlen(str); |
745 | |
|
746 | 0 | if (marker_idx < 0) marker_idx = marker_idx * -1; |
747 | |
|
748 | 0 | if ((size_t)marker_idx >= sizeof(marker_spaces)) { |
749 | 0 | size_t offset = (marker_idx - (sizeof(marker_spaces) - 1)) + (sizeof(marker_spaces) * 0.75); |
750 | 0 | marker_idx -= offset; |
751 | |
|
752 | 0 | if (offset > str_len) offset = str_len; |
753 | 0 | str += offset; |
754 | 0 | str_len -= offset; |
755 | |
|
756 | 0 | ellipses = "... "; |
757 | 0 | } |
758 | |
|
759 | 0 | if (line_prefix_fmt) { |
760 | 0 | va_start(ap, line_prefix_fmt); |
761 | 0 | line_prefix = fr_vasprintf(thread_log_pool, line_prefix_fmt, ap); |
762 | 0 | va_end(ap); |
763 | 0 | } |
764 | |
|
765 | 0 | fr_log(log, type, file, line, "%s%s%.*s", |
766 | 0 | line_prefix ? line_prefix : "", ellipses, (int)str_len, str); |
767 | 0 | fr_log(log, type, file, line, "%s%s%.*s^ %s", |
768 | 0 | line_prefix ? line_prefix : "", ellipses, (int)marker_idx, marker_spaces, marker); |
769 | |
|
770 | 0 | if (line_prefix_fmt) talloc_free(line_prefix); |
771 | 0 | } |
772 | | |
773 | | /** Print out hex block |
774 | | * |
775 | | * @param[in] log destination. |
776 | | * @param[in] type of log message. |
777 | | * @param[in] file src file the log message was generated in. |
778 | | * @param[in] line number the log message was generated on. |
779 | | * @param[in] data to print. |
780 | | * @param[in] data_len length of data. |
781 | | * @param[in] line_prefix_fmt Prefix to add to the marker messages. |
782 | | * @param[in] ... Arguments for line_prefix_fmt. |
783 | | */ |
784 | | void fr_log_hex(fr_log_t const *log, fr_log_type_t type, char const *file, int line, |
785 | | uint8_t const *data, size_t data_len, char const *line_prefix_fmt, ...) |
786 | 0 | { |
787 | 0 | size_t i, j, len; |
788 | 0 | char buffer[(0x10 * 3) + 1]; |
789 | 0 | char *p, *end = buffer + sizeof(buffer); |
790 | 0 | TALLOC_CTX *thread_log_pool = fr_log_pool_init(); |
791 | 0 | char *line_prefix = NULL; |
792 | |
|
793 | 0 | if (line_prefix_fmt) { |
794 | 0 | va_list ap; |
795 | |
|
796 | 0 | va_start(ap, line_prefix_fmt); |
797 | 0 | line_prefix = fr_vasprintf(thread_log_pool, line_prefix_fmt, ap); |
798 | 0 | va_end(ap); |
799 | 0 | } |
800 | |
|
801 | 0 | for (i = 0; i < data_len; i += 0x10) { |
802 | 0 | len = 0x10; |
803 | 0 | if ((i + len) > data_len) len = data_len - i; |
804 | |
|
805 | 0 | for (p = buffer, j = 0; j < len; j++, p += 3) snprintf(p, end - p, "%02x ", data[i + j]); |
806 | |
|
807 | 0 | if (line_prefix_fmt) { |
808 | 0 | fr_log(log, type, file, line, "%s%04x: %s", |
809 | 0 | line_prefix, (int)i, buffer); |
810 | 0 | } else { |
811 | 0 | fr_log(log, type, file, line, "%04x: %s", (int)i, buffer); |
812 | 0 | } |
813 | 0 | } |
814 | |
|
815 | 0 | if (line_prefix_fmt) talloc_free(line_prefix); |
816 | 0 | } |
817 | | |
818 | | /** Print out hex block |
819 | | * |
820 | | * @param[in] log destination. |
821 | | * @param[in] type of log message. |
822 | | * @param[in] file src file the log message was generated in. |
823 | | * @param[in] line number the log message was generated on. |
824 | | * @param[in] data to print. |
825 | | * @param[in] data_len length of data. |
826 | | * @param[in] marker_idx Where to place the marker. May be negative. |
827 | | * @param[in] marker text to print at marker_idx. |
828 | | * @param[in] line_prefix_fmt Prefix to add to the marker messages. |
829 | | * @param[in] ... Arguments for line_prefix_fmt. |
830 | | */ |
831 | | void fr_log_hex_marker(fr_log_t const *log, fr_log_type_t type, char const *file, int line, |
832 | | uint8_t const *data, size_t data_len, |
833 | | ssize_t marker_idx, char const *marker, char const *line_prefix_fmt, ...) |
834 | 0 | { |
835 | 0 | size_t i, j, len; |
836 | 0 | char buffer[(0x10 * 3) + 1]; |
837 | 0 | char *p, *end = buffer + sizeof(buffer); |
838 | 0 | TALLOC_CTX *thread_log_pool = fr_log_pool_init(); |
839 | |
|
840 | 0 | char *line_prefix = NULL; |
841 | 0 | static char spaces[3 * 0x10]; /* Bytes per line */ |
842 | |
|
843 | 0 | if (!*spaces) memset(spaces, ' ', sizeof(spaces) - 1); /* Leave a \0 */ |
844 | |
|
845 | 0 | if (marker_idx < 0) marker_idx = marker_idx * -1; |
846 | 0 | if (line_prefix_fmt) { |
847 | 0 | va_list ap; |
848 | |
|
849 | 0 | va_start(ap, line_prefix_fmt); |
850 | 0 | line_prefix = fr_vasprintf(thread_log_pool, line_prefix_fmt, ap); |
851 | 0 | va_end(ap); |
852 | 0 | } |
853 | |
|
854 | 0 | for (i = 0; i < data_len; i += 0x10) { |
855 | 0 | len = 0x10; |
856 | 0 | if ((i + len) > data_len) len = data_len - i; |
857 | |
|
858 | 0 | for (p = buffer, j = 0; j < len; j++, p += 3) snprintf(p, end - p, "%02x ", data[i + j]); |
859 | |
|
860 | 0 | if (line_prefix_fmt) { |
861 | 0 | fr_log(log, type, file, line, "%s%04x: %s", |
862 | 0 | line_prefix, (int)i, buffer); |
863 | 0 | } else { |
864 | 0 | fr_log(log, type, file, line, "%04x: %s", (int)i, buffer); |
865 | 0 | } |
866 | | |
867 | | /* |
868 | | * Marker is on this line |
869 | | */ |
870 | 0 | if (((size_t)marker_idx >= i) && ((size_t)marker_idx < (i + 0x10))) { |
871 | 0 | if (line_prefix_fmt) { |
872 | 0 | fr_log(log, type, file, line, "%s %.*s^ %s", line_prefix, |
873 | 0 | (int)((marker_idx - i) * 3), spaces, marker); |
874 | 0 | } else { |
875 | 0 | fr_log(log, type, file, line, " %.*s^ %s", |
876 | 0 | (int)((marker_idx - i) * 3), spaces, marker); |
877 | 0 | } |
878 | 0 | } |
879 | 0 | } |
880 | |
|
881 | 0 | if (line_prefix_fmt) talloc_free(line_prefix); |
882 | 0 | } |
883 | | DIAG_ON(format-nonliteral) |
884 | | /** On fault, reset STDOUT and STDERR to something useful |
885 | | * |
886 | | * @return 0 |
887 | | */ |
888 | | static int _restore_std_legacy(UNUSED int sig) |
889 | 0 | { |
890 | 0 | if ((stderr_fd > 0) && (stdout_fd > 0)) { |
891 | 0 | dup2(stderr_fd, STDOUT_FILENO); |
892 | 0 | dup2(stdout_fd, STDERR_FILENO); |
893 | 0 | return 0; |
894 | 0 | } |
895 | | |
896 | 0 | return 0; |
897 | 0 | } |
898 | | |
899 | | /** Initialise file descriptors based on logging destination |
900 | | * |
901 | | * @param log Logger to manipulate. |
902 | | * @param daemonize Whether the server is starting as a daemon. |
903 | | * @return |
904 | | * - 0 on success. |
905 | | * - -1 on failure. |
906 | | */ |
907 | | int fr_log_init_legacy(fr_log_t *log, bool daemonize) |
908 | 0 | { |
909 | 0 | int devnull_legacy; |
910 | |
|
911 | 0 | fr_log_rate_limit = daemonize; |
912 | | |
913 | | /* |
914 | | * If we're running in foreground mode, save STDIN / |
915 | | * STDERR as higher FDs, which won't get used by anyone |
916 | | * else. When we fork/exec a program, its STD FDs will |
917 | | * get set to pipes. We later set STDOUT / STDERR to |
918 | | * /dev/null, so that any library trying to write to them |
919 | | * doesn't screw anything up. |
920 | | * |
921 | | * Then, when something goes wrong, restore them so that |
922 | | * any debugger called from the panic action has access |
923 | | * to STDOUT / STDERR. |
924 | | */ |
925 | 0 | if (!daemonize) { |
926 | 0 | fr_fault_set_cb(_restore_std_legacy); |
927 | |
|
928 | 0 | stdout_fd = dup(STDOUT_FILENO); |
929 | 0 | stderr_fd = dup(STDERR_FILENO); |
930 | 0 | } |
931 | |
|
932 | 0 | devnull_legacy = open("/dev/null", O_RDWR); |
933 | 0 | if (devnull_legacy < 0) { |
934 | 0 | fr_strerror_printf("Error opening /dev/null: %s", fr_syserror(errno)); |
935 | 0 | return -1; |
936 | 0 | } |
937 | | |
938 | | /* |
939 | | * STDOUT & STDERR go to /dev/null, unless we have "-x", |
940 | | * then STDOUT & STDERR go to the "-l log" destination. |
941 | | * |
942 | | * The complexity here is because "-l log" can go to |
943 | | * STDOUT or STDERR, too. |
944 | | */ |
945 | 0 | if (log->dst == L_DST_STDOUT) { |
946 | 0 | setlinebuf(stdout); |
947 | 0 | log->fd = STDOUT_FILENO; |
948 | | |
949 | | /* |
950 | | * If we're debugging, allow STDERR to go to |
951 | | * STDOUT too, for executed programs. |
952 | | * |
953 | | * Allow stdout when running in foreground mode |
954 | | * as it's useful for some profiling tools, |
955 | | * like mutrace. |
956 | | */ |
957 | 0 | if (fr_debug_lvl || !daemonize) { |
958 | 0 | dup2(STDOUT_FILENO, STDERR_FILENO); |
959 | 0 | } else { |
960 | 0 | dup2(devnull_legacy, STDERR_FILENO); |
961 | 0 | } |
962 | |
|
963 | 0 | } else if (log->dst == L_DST_STDERR) { |
964 | 0 | setlinebuf(stderr); |
965 | 0 | log->fd = STDERR_FILENO; |
966 | | |
967 | | /* |
968 | | * If we're debugging, allow STDOUT to go to |
969 | | * STDERR too, for executed programs. |
970 | | * |
971 | | * Allow stdout when running in foreground mode |
972 | | * as it's useful for some profiling tools, |
973 | | * like mutrace. |
974 | | */ |
975 | 0 | if (fr_debug_lvl || !daemonize) { |
976 | 0 | dup2(STDERR_FILENO, STDOUT_FILENO); |
977 | 0 | } else { |
978 | 0 | dup2(devnull_legacy, STDOUT_FILENO); |
979 | 0 | } |
980 | |
|
981 | 0 | } else if (log->dst == L_DST_SYSLOG) { |
982 | | /* |
983 | | * Discard STDOUT and STDERR no matter what the |
984 | | * status of debugging. Syslog isn't a file |
985 | | * descriptor, so we can't use it. |
986 | | */ |
987 | 0 | dup2(devnull_legacy, STDOUT_FILENO); |
988 | 0 | dup2(devnull_legacy, STDERR_FILENO); |
989 | 0 | log->print_level = false; |
990 | |
|
991 | 0 | } else if (fr_debug_lvl) { |
992 | | /* |
993 | | * If we're debugging, allow STDOUT and STDERR to |
994 | | * go to the log file. |
995 | | */ |
996 | 0 | dup2(log->fd, STDOUT_FILENO); |
997 | 0 | dup2(log->fd, STDERR_FILENO); |
998 | |
|
999 | 0 | } else { |
1000 | | /* |
1001 | | * Not debugging, and the log isn't STDOUT or |
1002 | | * STDERR. Ensure that we move both of them to |
1003 | | * /dev/null, so that the calling terminal can |
1004 | | * exit, and the output from executed programs |
1005 | | * doesn't pollute STDOUT / STDERR. |
1006 | | */ |
1007 | 0 | dup2(devnull_legacy, STDOUT_FILENO); |
1008 | 0 | dup2(devnull_legacy, STDERR_FILENO); |
1009 | 0 | } |
1010 | |
|
1011 | 0 | close(devnull_legacy); |
1012 | |
|
1013 | 0 | fr_fault_set_log_fd(log->fd); |
1014 | |
|
1015 | 0 | return 0; |
1016 | 0 | } |
1017 | | |
1018 | | DIAG_ON(format-nonliteral) |
1019 | | |
1020 | | /** Initialise log dst for stdout, stderr or /dev/null |
1021 | | * |
1022 | | * @param[out] log Destination to initialise. |
1023 | | * @param[in] dst_type The specific type of log destination to initialise. |
1024 | | * @return |
1025 | | * - 0 on success. |
1026 | | * - -1 on failure. |
1027 | | */ |
1028 | | int fr_log_init_std(fr_log_t *log, fr_log_dst_t dst_type) |
1029 | 0 | { |
1030 | 0 | memset(log, 0, sizeof(*log)); |
1031 | |
|
1032 | 0 | log->dst = dst_type; |
1033 | 0 | switch (log->dst) { |
1034 | 0 | case L_DST_STDOUT: |
1035 | 0 | log->handle = stdout; |
1036 | 0 | break; |
1037 | | |
1038 | 0 | case L_DST_STDERR: |
1039 | 0 | log->handle = stderr; |
1040 | 0 | break; |
1041 | | |
1042 | 0 | case L_DST_NULL: |
1043 | 0 | log->handle = devnull; |
1044 | 0 | break; |
1045 | | |
1046 | 0 | default: |
1047 | 0 | fr_strerror_const("Invalid dst type for FD log destination"); |
1048 | 0 | return -1; |
1049 | 0 | } |
1050 | | |
1051 | 0 | return 0; |
1052 | 0 | } |
1053 | | |
1054 | | /** Initialise a file logging destination to a FILE* |
1055 | | * |
1056 | | * @param[out] log Destination to initialise. |
1057 | | * @param[in] fp pre-existing handle |
1058 | | * @return |
1059 | | * - 0 on success. |
1060 | | * - -1 on failure. |
1061 | | */ |
1062 | | int fr_log_init_fp(fr_log_t *log, FILE *fp) |
1063 | 0 | { |
1064 | 0 | memset(log, 0, sizeof(*log)); |
1065 | |
|
1066 | 0 | log->dst = L_DST_FILES; |
1067 | 0 | log->handle = fp; |
1068 | |
|
1069 | 0 | setlinebuf(log->handle); |
1070 | 0 | log->fd = fileno(log->handle); |
1071 | |
|
1072 | 0 | return 0; |
1073 | 0 | } |
1074 | | |
1075 | | /** Initialise a file logging destination |
1076 | | * |
1077 | | * @param[out] log Destination to initialise. |
1078 | | * @param[in] file to open handle for. |
1079 | | * @return |
1080 | | * - 0 on success. |
1081 | | * - -1 on failure. |
1082 | | */ |
1083 | | int fr_log_init_file(fr_log_t *log, char const *file) |
1084 | 0 | { |
1085 | 0 | FILE *fp; |
1086 | |
|
1087 | 0 | if (unlikely((fp = fopen(file, "a")) == NULL)) { |
1088 | 0 | fr_strerror_printf("Failed opening log file \"%s\": %s", file, fr_syserror(errno)); |
1089 | 0 | return -1; |
1090 | 0 | } |
1091 | | |
1092 | 0 | return fr_log_init_fp(log, fp); |
1093 | 0 | } |
1094 | | |
1095 | | /** Write complete lines to syslog |
1096 | | * |
1097 | | */ |
1098 | | static ssize_t _syslog_write(UNUSED void *cookie, const char *buf, size_t size) |
1099 | 0 | { |
1100 | 0 | static int syslog_priority_table[] = { |
1101 | 0 | [L_DBG] = LOG_DEBUG, |
1102 | |
|
1103 | 0 | [L_INFO] = LOG_INFO, |
1104 | 0 | [L_DBG_INFO] = LOG_INFO, |
1105 | |
|
1106 | 0 | [L_ERR] = LOG_ERR, |
1107 | 0 | [L_DBG_ERR] = LOG_ERR, |
1108 | 0 | [L_DBG_ERR_REQ] = LOG_ERR, |
1109 | |
|
1110 | 0 | [L_WARN] = LOG_WARNING, |
1111 | 0 | [L_DBG_WARN] = LOG_WARNING, |
1112 | 0 | [L_DBG_WARN_REQ] = LOG_WARNING, |
1113 | |
|
1114 | 0 | [L_AUTH] = LOG_AUTH | LOG_INFO |
1115 | 0 | }; |
1116 | |
|
1117 | 0 | syslog(syslog_priority_table[log_msg_type], "%.*s", (int)size, buf); |
1118 | |
|
1119 | 0 | return size; |
1120 | 0 | } |
1121 | | |
1122 | | /** Initialise a syslog logging destination |
1123 | | * |
1124 | | * @param[out] log Destination to initialise. |
1125 | | * @return |
1126 | | * - 0 on success. |
1127 | | * - -1 on failure. |
1128 | | */ |
1129 | | int fr_log_init_syslog(fr_log_t *log) |
1130 | 0 | { |
1131 | 0 | memset(log, 0, sizeof(*log)); |
1132 | |
|
1133 | 0 | log->dst = L_DST_SYSLOG; |
1134 | 0 | if (unlikely((log->handle = fopencookie(log, "w", |
1135 | 0 | (cookie_io_functions_t){ |
1136 | 0 | .write = _syslog_write, |
1137 | 0 | })) == NULL)) { |
1138 | 0 | fr_strerror_printf("Failed opening syslog transpor: %s", fr_syserror(errno)); |
1139 | 0 | return -1; |
1140 | 0 | } |
1141 | | |
1142 | 0 | setlinebuf(log->handle); |
1143 | |
|
1144 | 0 | return 0; |
1145 | 0 | } |
1146 | | |
1147 | | /** Initialise a function based logging destination |
1148 | | * |
1149 | | * @note Cookie functions receive the fr_log_t which contains the uctx, not the uctx directly. |
1150 | | * |
1151 | | * @param[out] log Destination to initialise. |
1152 | | * @param[in] write Called when a complete log line is ready for writing. |
1153 | | * @param[in] close May be NULL. Called when the logging destination has been closed. |
1154 | | * @param[in] uctx for the write and close functions. |
1155 | | * @return |
1156 | | * - 0 on success. |
1157 | | * - -1 on failure. |
1158 | | */ |
1159 | | int fr_log_init_func(fr_log_t *log, cookie_write_function_t write, cookie_close_function_t close, void *uctx) |
1160 | 0 | { |
1161 | 0 | memset(log, 0, sizeof(*log)); |
1162 | |
|
1163 | 0 | log->dst = L_DST_FUNC; |
1164 | |
|
1165 | 0 | if (unlikely((log->handle = fopencookie(log, "w", |
1166 | 0 | (cookie_io_functions_t){ |
1167 | 0 | .write = write, |
1168 | 0 | .close = close |
1169 | 0 | })) == NULL)) { |
1170 | 0 | fr_strerror_printf("Failed opening func transport: %s", fr_syserror(errno)); |
1171 | 0 | return -1; |
1172 | 0 | } |
1173 | | |
1174 | 0 | setlinebuf(log->handle); |
1175 | 0 | log->uctx = uctx; |
1176 | |
|
1177 | 0 | return 0; |
1178 | 0 | } |
1179 | | |
1180 | | /** Universal close function for all logging destinations |
1181 | | * |
1182 | | */ |
1183 | | int fr_log_close(fr_log_t *log) |
1184 | 0 | { |
1185 | 0 | switch (log->dst) { |
1186 | 0 | case L_DST_STDOUT: |
1187 | 0 | case L_DST_STDERR: |
1188 | 0 | case L_DST_NULL: |
1189 | 0 | return 0; |
1190 | | |
1191 | | /* |
1192 | | * Other log dsts |
1193 | | */ |
1194 | 0 | case L_DST_FILES: |
1195 | 0 | case L_DST_FUNC: |
1196 | 0 | case L_DST_SYSLOG: |
1197 | 0 | if (log->handle && (fclose(log->handle) < 0)) { |
1198 | 0 | fr_strerror_printf("Failed closing file handle: %s", fr_syserror(errno)); |
1199 | 0 | return -1; |
1200 | 0 | } |
1201 | 0 | return 0; |
1202 | | |
1203 | 0 | case L_DST_NUM_DEST: |
1204 | 0 | break; |
1205 | 0 | } |
1206 | | |
1207 | 0 | fr_strerror_printf("Failed closing invalid log dst %i", log->dst); |
1208 | 0 | return -1; |
1209 | 0 | } |
1210 | | |
1211 | | /** Manipulate stderr and stdout so that was capture all data send to it from libraries |
1212 | | * |
1213 | | * @param[in] el The event list we use to process logging data. |
1214 | | * @param[in] daemonize Whether the server is starting as a daemon. |
1215 | | * @return |
1216 | | * - 0 on success. |
1217 | | * - -1 on failure. |
1218 | | */ |
1219 | | int fr_log_global_init(fr_event_list_t *el, bool daemonize) |
1220 | 0 | { |
1221 | 0 | log_el = el; |
1222 | |
|
1223 | 0 | fr_log_rate_limit = daemonize; |
1224 | | |
1225 | | /* |
1226 | | * dup the current stdout/stderr FDs and close |
1227 | | * the FDs in the STDOUT/STDERR slots to get |
1228 | | * the reference count back to one. |
1229 | | */ |
1230 | 0 | stdout_fd = dup(STDOUT_FILENO); |
1231 | 0 | if (unlikely(stdout_fd < 0)) { |
1232 | 0 | fr_strerror_printf("Failed cloning stdout FD: %s", fr_syserror(errno)); |
1233 | 0 | return -1; |
1234 | 0 | } |
1235 | | |
1236 | | /* |
1237 | | * Create two unidirection pipes, duping one end |
1238 | | * to the stdout/stderr slots and inserting the |
1239 | | * other into our event loop |
1240 | | */ |
1241 | 0 | if (unlikely(pipe(stdout_pipe) < 0)) { |
1242 | 0 | fr_strerror_printf("Failed creating logging pipes: %s", fr_syserror(errno)); |
1243 | 0 | error_0: |
1244 | 0 | log_el = NULL; |
1245 | 0 | close(stdout_fd); |
1246 | 0 | return -1; |
1247 | 0 | } |
1248 | | |
1249 | | /* |
1250 | | * This closes the other ref to the stdout FD. |
1251 | | */ |
1252 | 0 | if (unlikely(dup2(stdout_pipe[0], STDOUT_FILENO) < 0)) { |
1253 | 0 | fr_strerror_printf("Failed copying pipe end over stdout: %s", fr_syserror(errno)); |
1254 | 0 | error_1: |
1255 | 0 | close(stdout_pipe[0]); |
1256 | 0 | stdout_pipe[0] = -1; |
1257 | 0 | close(stdout_pipe[1]); |
1258 | 0 | stdout_pipe[1] = -1; |
1259 | 0 | goto error_0; |
1260 | 0 | } |
1261 | | |
1262 | 0 | stdout_ctx.dst = &default_log; |
1263 | 0 | stdout_ctx.prefix = "(stdout)"; |
1264 | 0 | stdout_ctx.type = L_DBG; |
1265 | 0 | stdout_ctx.lvl = L_DBG_LVL_2; |
1266 | | |
1267 | | /* |
1268 | | * Now do stderr... |
1269 | | */ |
1270 | 0 | if (unlikely(fr_event_fd_insert(NULL, NULL, el, stdout_pipe[1], fr_log_fd_event, NULL, NULL, &stdout_ctx) < 0)) { |
1271 | 0 | fr_strerror_const_push("Failed adding stdout handler to event loop"); |
1272 | 0 | error_2: |
1273 | 0 | dup2(STDOUT_FILENO, stdout_fd); /* Copy back the stdout FD */ |
1274 | 0 | goto error_1; |
1275 | 0 | } |
1276 | | |
1277 | 0 | stderr_fd = dup(STDERR_FILENO); |
1278 | 0 | if (unlikely(stderr_fd < 0)) { |
1279 | 0 | fr_strerror_printf("Failed cloning stderr FD: %s", fr_syserror(errno)); |
1280 | |
|
1281 | 0 | error_3: |
1282 | 0 | fr_event_fd_delete(el, stdout_pipe[1], FR_EVENT_FILTER_IO); |
1283 | 0 | goto error_2; |
1284 | 0 | } |
1285 | | |
1286 | 0 | if (unlikely(pipe(stderr_pipe) < 0)) { |
1287 | 0 | fr_strerror_printf("Failed creating logging pipes: %s", fr_syserror(errno)); |
1288 | 0 | error_4: |
1289 | 0 | close(stderr_fd); |
1290 | 0 | goto error_3; |
1291 | 0 | } |
1292 | | |
1293 | 0 | if (unlikely(dup2(stderr_pipe[0], STDOUT_FILENO) < 0)) { |
1294 | 0 | fr_strerror_printf("Failed copying pipe end over stderr: %s", fr_syserror(errno)); |
1295 | 0 | error_5: |
1296 | 0 | close(stderr_pipe[0]); |
1297 | 0 | stderr_pipe[0] = -1; |
1298 | 0 | close(stderr_pipe[1]); |
1299 | 0 | stderr_pipe[1] = -1; |
1300 | 0 | goto error_4; |
1301 | 0 | } |
1302 | | |
1303 | 0 | stdout_ctx.dst = &default_log; |
1304 | 0 | stdout_ctx.prefix = "(stderr)"; |
1305 | 0 | stdout_ctx.type = L_ERR; |
1306 | 0 | stdout_ctx.lvl = L_DBG_LVL_OFF; /* Log at all debug levels */ |
1307 | |
|
1308 | 0 | if (unlikely(fr_event_fd_insert(NULL, NULL, el, stderr_pipe[1], fr_log_fd_event, NULL, NULL, &stderr_ctx) < 0)) { |
1309 | 0 | fr_strerror_const_push("Failed adding stdout handler to event loop"); |
1310 | 0 | error_6: |
1311 | 0 | dup2(STDERR_FILENO, stderr_fd); /* Copy back the stderr FD */ |
1312 | 0 | goto error_5; |
1313 | 0 | } |
1314 | | |
1315 | 0 | fr_fault_set_log_fd(STDERR_FILENO); |
1316 | 0 | fr_fault_set_cb(_restore_std_legacy); /* Restore the original file descriptors if we experience a fault */ |
1317 | | |
1318 | | /* |
1319 | | * Setup our standard file *s |
1320 | | */ |
1321 | 0 | setlinebuf(stdout); |
1322 | 0 | setlinebuf(stderr); |
1323 | |
|
1324 | 0 | devnull = fopen("/dev/null", "w"); |
1325 | 0 | if (unlikely(!devnull)) { |
1326 | 0 | fr_strerror_printf("Error opening /dev/null: %s", fr_syserror(errno)); |
1327 | 0 | goto error_6; |
1328 | 0 | } |
1329 | | |
1330 | 0 | fr_log_init_std(&default_log, L_DST_STDOUT); |
1331 | |
|
1332 | 0 | return 0; |
1333 | 0 | } |
1334 | | |
1335 | | /** Restores the original stdout and stderr FDs, closes the pipes and removes them from the event loop |
1336 | | * |
1337 | | */ |
1338 | | void fr_log_global_free(void) |
1339 | 0 | { |
1340 | 0 | if (!log_el) return; |
1341 | | |
1342 | 0 | fr_event_fd_delete(log_el, stdout_pipe[1], FR_EVENT_FILTER_IO); |
1343 | 0 | close(stdout_pipe[1]); |
1344 | 0 | stdout_pipe[1] = -1; |
1345 | 0 | fr_event_fd_delete(log_el, stderr_pipe[1], FR_EVENT_FILTER_IO); |
1346 | 0 | close(stderr_pipe[1]); |
1347 | 0 | stderr_pipe[1] = -1; |
1348 | |
|
1349 | 0 | _restore_std_legacy(0); /* Will close stdout_pipe[0] and stderr_pipe[0] with dup2 */ |
1350 | |
|
1351 | 0 | stdout_pipe[0] = -1; |
1352 | 0 | stderr_pipe[0] = -1; |
1353 | |
|
1354 | 0 | fclose(devnull); |
1355 | 0 | } |