/src/kamailio/src/core/dprint.c
Line | Count | Source (jump to first uncovered line) |
1 | | /* |
2 | | * debug print |
3 | | * |
4 | | * Copyright (C) 2001-2003 FhG Fokus |
5 | | * |
6 | | * This file is part of Kamailio, a free SIP server. |
7 | | * |
8 | | * Kamailio 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 2 of the License, or |
11 | | * (at your option) any later version |
12 | | * |
13 | | * Kamailio 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, write to the Free Software |
20 | | * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA |
21 | | */ |
22 | | /*! |
23 | | * \file |
24 | | * \brief Kamailio core :: Debug print |
25 | | * \ingroup core |
26 | | * Module: \ref core |
27 | | */ |
28 | | |
29 | | |
30 | | #ifdef KSR_PTHREAD_MUTEX_SHARED |
31 | | #define HAVE_PTHREAD |
32 | | #include <pthread.h> |
33 | | #endif |
34 | | #include <stdlib.h> |
35 | | #include <stdarg.h> |
36 | | #include <stdio.h> |
37 | | #include <strings.h> |
38 | | #include <stdint.h> |
39 | | |
40 | | #include "globals.h" |
41 | | #include "dprint.h" |
42 | | #include "pvar.h" |
43 | | #include "strutils.h" |
44 | | |
45 | | static void log_callid_set(sip_msg_t *msg); |
46 | | |
47 | | char *_km_log_engine_type = NULL; |
48 | | char *_km_log_engine_data = NULL; |
49 | | |
50 | | km_log_f _km_log_func = &syslog; |
51 | | |
52 | | /** |
53 | | * |
54 | | */ |
55 | | void km_log_func_set(km_log_f f) |
56 | 0 | { |
57 | 0 | _km_log_func = f; |
58 | 0 | } |
59 | | |
60 | | #ifndef NO_SIG_DEBUG |
61 | | /* signal protection: !=0 when LOG/DBG/... are printing */ |
62 | | volatile int dprint_crit = 0; |
63 | | #endif |
64 | | |
65 | | static char *str_fac[] = {"LOG_AUTH", "LOG_CRON", "LOG_DAEMON", "LOG_KERN", |
66 | | "LOG_LOCAL0", "LOG_LOCAL1", "LOG_LOCAL2", "LOG_LOCAL3", "LOG_LOCAL4", |
67 | | "LOG_LOCAL5", "LOG_LOCAL6", "LOG_LOCAL7", "LOG_LPR", "LOG_MAIL", |
68 | | "LOG_NEWS", "LOG_USER", "LOG_UUCP", |
69 | | #ifndef __OS_solaris |
70 | | "LOG_AUTHPRIV", "LOG_FTP", "LOG_SYSLOG", |
71 | | #endif |
72 | | 0}; |
73 | | |
74 | | static int int_fac[] = {LOG_AUTH, LOG_CRON, LOG_DAEMON, LOG_KERN, LOG_LOCAL0, |
75 | | LOG_LOCAL1, LOG_LOCAL2, LOG_LOCAL3, LOG_LOCAL4, LOG_LOCAL5, LOG_LOCAL6, |
76 | | LOG_LOCAL7, LOG_LPR, LOG_MAIL, LOG_NEWS, LOG_USER, LOG_UUCP, |
77 | | #ifndef __OS_solaris |
78 | | LOG_AUTHPRIV, LOG_FTP, LOG_SYSLOG, |
79 | | #endif |
80 | | 0}; |
81 | | |
82 | | struct log_level_info log_level_info[] = { |
83 | | {"ALERT", LOG_ALERT}, /* L_ALERT */ |
84 | | {"BUG", LOG_CRIT}, /* L_BUG */ |
85 | | {"CRITICAL", LOG_CRIT}, /* L_CRIT2 */ |
86 | | {"", LOG_CRIT}, /* L_CRIT */ |
87 | | {"ERROR", LOG_ERR}, /* L_ERR */ |
88 | | {"WARNING", LOG_WARNING}, /* L_WARN */ |
89 | | {"NOTICE", LOG_NOTICE}, /* L_NOTICE */ |
90 | | {"INFO", LOG_INFO}, /* L_INFO */ |
91 | | {"DEBUG", LOG_DEBUG} /* L_DBG */ |
92 | | }; |
93 | | |
94 | | int str2facility(char *s) |
95 | 0 | { |
96 | 0 | int i; |
97 | |
|
98 | 0 | for(i = 0; str_fac[i]; i++) { |
99 | 0 | if(!strcasecmp(s, str_fac[i])) |
100 | 0 | return int_fac[i]; |
101 | 0 | } |
102 | 0 | return -1; |
103 | 0 | } |
104 | | |
105 | | char *facility2str(int fl, int *len) |
106 | 0 | { |
107 | 0 | int i; |
108 | |
|
109 | 0 | for(i = 0; str_fac[i]; i++) { |
110 | 0 | if(fl == int_fac[i]) { |
111 | 0 | *len = strlen(str_fac[i]); |
112 | 0 | return str_fac[i]; |
113 | 0 | } |
114 | 0 | } |
115 | | |
116 | 0 | return NULL; |
117 | 0 | } |
118 | | |
119 | | /* fixup function for log_facility cfg parameter */ |
120 | | int log_facility_fixup(void *handle, str *gname, str *name, void **val) |
121 | 0 | { |
122 | 0 | int i; |
123 | |
|
124 | 0 | if((i = str2facility((char *)*val)) == -1) { |
125 | 0 | LM_ERR("invalid log facility: %s\n", (char *)*val); |
126 | 0 | return -1; |
127 | 0 | } |
128 | 0 | *val = (void *)(long)i; |
129 | 0 | return 0; |
130 | 0 | } |
131 | | |
132 | | |
133 | | /** |
134 | | * per process debug log level (local) |
135 | | */ |
136 | | |
137 | | /* value for unset local log level */ |
138 | 1.09M | #define UNSET_LOCAL_DEBUG_LEVEL -255 |
139 | 426k | #define UNSET_LOCAL_DEBUG_FACILITY -255 |
140 | | |
141 | | /* the local debug log level */ |
142 | | static int _local_debug_level = UNSET_LOCAL_DEBUG_LEVEL; |
143 | | static int _local_debug_facility = UNSET_LOCAL_DEBUG_FACILITY; |
144 | | /* callback to get per module debug level */ |
145 | | static get_module_debug_level_f _module_debug_level = NULL; |
146 | | static get_module_debug_facility_f _module_debug_facility = NULL; |
147 | | |
148 | | /** |
149 | | * @brief set callback function for per module debug level |
150 | | */ |
151 | | void set_module_debug_level_cb(get_module_debug_level_f f) |
152 | 0 | { |
153 | 0 | _module_debug_level = f; |
154 | 0 | } |
155 | | |
156 | | void set_module_debug_facility_cb(get_module_debug_facility_f f) |
157 | 0 | { |
158 | 0 | _module_debug_facility = f; |
159 | 0 | } |
160 | | |
161 | | /** |
162 | | * @brief return the log level - the local one if it set, |
163 | | * otherwise the global value |
164 | | */ |
165 | | int get_debug_level(char *mname, int mnlen) |
166 | 1.09M | { |
167 | 1.09M | int mlevel; |
168 | | /*important -- no LOGs inside, because it will loop */ |
169 | 1.09M | if(unlikely(_module_debug_level != NULL && mnlen > 0)) { |
170 | 0 | if(_module_debug_level(mname, mnlen, &mlevel) == 0) { |
171 | 0 | return mlevel; |
172 | 0 | } |
173 | 0 | } |
174 | 1.09M | return (_local_debug_level != UNSET_LOCAL_DEBUG_LEVEL) |
175 | 1.09M | ? _local_debug_level |
176 | 1.09M | : cfg_get(core, core_cfg, debug); |
177 | 1.09M | } |
178 | | |
179 | | /** |
180 | | * @brief return the log level - the local one if it set, |
181 | | * otherwise the global value |
182 | | */ |
183 | | int get_cfg_debug_level(void) |
184 | 0 | { |
185 | | /*important -- no LOGs inside, because it will loop */ |
186 | 0 | return (_local_debug_level != UNSET_LOCAL_DEBUG_LEVEL) |
187 | 0 | ? _local_debug_level |
188 | 0 | : cfg_get(core, core_cfg, debug); |
189 | 0 | } |
190 | | |
191 | | /** |
192 | | * @brief return the log facility - the local one if it set, |
193 | | * otherwise the global value |
194 | | */ |
195 | | int get_debug_facility(char *mname, int mnlen) |
196 | 426k | { |
197 | 426k | int mfacility; |
198 | | /*important -- no LOGs inside, because it will loop */ |
199 | 426k | if(unlikely(_module_debug_facility != NULL && mnlen > 0)) { |
200 | 0 | if(_module_debug_facility(mname, mnlen, &mfacility) == 0) { |
201 | 0 | return mfacility; |
202 | 0 | } |
203 | 0 | } |
204 | 426k | return (_local_debug_facility != UNSET_LOCAL_DEBUG_FACILITY) |
205 | 426k | ? _local_debug_facility |
206 | 426k | : cfg_get(core, core_cfg, log_facility); |
207 | 426k | } |
208 | | |
209 | | |
210 | | /** |
211 | | * @brief set the local debug log level |
212 | | */ |
213 | | void set_local_debug_level(int level) |
214 | 0 | { |
215 | 0 | _local_debug_level = level; |
216 | 0 | } |
217 | | |
218 | | /** |
219 | | * @brief reset the local debug log level |
220 | | */ |
221 | | void reset_local_debug_level(void) |
222 | 0 | { |
223 | 0 | _local_debug_level = UNSET_LOCAL_DEBUG_LEVEL; |
224 | 0 | } |
225 | | |
226 | | /** |
227 | | * @brief set the local debug log facility |
228 | | */ |
229 | | void set_local_debug_facility(int facility) |
230 | 0 | { |
231 | 0 | _local_debug_facility = facility; |
232 | 0 | } |
233 | | |
234 | | /** |
235 | | * @brief reset the local debug log facility |
236 | | */ |
237 | | void reset_local_debug_facility(void) |
238 | 0 | { |
239 | 0 | _local_debug_facility = UNSET_LOCAL_DEBUG_FACILITY; |
240 | 0 | } |
241 | | |
242 | | typedef struct log_level_color |
243 | | { |
244 | | char f; |
245 | | char b; |
246 | | } log_level_color_t; |
247 | | |
248 | | log_level_color_t _log_level_colors[L_MAX - L_MIN + 1]; |
249 | | |
250 | | void dprint_init_colors(void) |
251 | 0 | { |
252 | 0 | int i; |
253 | |
|
254 | 0 | i = 0; |
255 | |
|
256 | 0 | memset(_log_level_colors, 0, |
257 | 0 | (L_MAX - L_MIN + 1) * sizeof(log_level_color_t)); |
258 | | |
259 | | /* L_ALERT */ |
260 | 0 | _log_level_colors[i].f = 'R'; /* default */ |
261 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
262 | 0 | i++; |
263 | | |
264 | | /* L_BUG */ |
265 | 0 | _log_level_colors[i].f = 'P'; /* default */ |
266 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
267 | 0 | i++; |
268 | | |
269 | | /* L_CRIT2 */ |
270 | 0 | _log_level_colors[i].f = 'y'; /* default */ |
271 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
272 | 0 | i++; |
273 | | |
274 | | /* L_CRIT */ |
275 | 0 | _log_level_colors[i].f = 'b'; /* default */ |
276 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
277 | 0 | i++; |
278 | | |
279 | | /* L_ERR */ |
280 | 0 | _log_level_colors[i].f = 'r'; /* default */ |
281 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
282 | 0 | i++; |
283 | | |
284 | | /* L_WARN */ |
285 | 0 | _log_level_colors[i].f = 'p'; /* default */ |
286 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
287 | 0 | i++; |
288 | | |
289 | | /* L_NOTICE */ |
290 | 0 | _log_level_colors[i].f = 'g'; /* default */ |
291 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
292 | 0 | i++; |
293 | | |
294 | | /* L_INFO */ |
295 | 0 | _log_level_colors[i].f = 'c'; /* default */ |
296 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
297 | 0 | i++; |
298 | | |
299 | | /* L_DBG */ |
300 | 0 | _log_level_colors[i].f = 'x'; /* default */ |
301 | 0 | _log_level_colors[i].b = 'x'; /* default */ |
302 | 0 | i++; |
303 | 0 | } |
304 | | |
305 | 0 | #define TERM_COLOR_SIZE 16 |
306 | | |
307 | | #define dprint_termc_add(p, end, s) \ |
308 | 0 | do { \ |
309 | 0 | if((p) + (sizeof(s) - 1) <= (end)) { \ |
310 | 0 | memcpy((p), s, sizeof(s) - 1); \ |
311 | 0 | (p) += sizeof(s) - 1; \ |
312 | 0 | } else { \ |
313 | 0 | /* overflow */ \ |
314 | 0 | LM_ERR("dprint_termc_add overflow\n"); \ |
315 | 0 | goto error; \ |
316 | 0 | } \ |
317 | 0 | } while(0) |
318 | | |
319 | | |
320 | | void dprint_term_color(char f, char b, str *obuf) |
321 | 0 | { |
322 | 0 | static char term_color[TERM_COLOR_SIZE]; |
323 | 0 | char *p; |
324 | 0 | char *end; |
325 | |
|
326 | 0 | p = term_color; |
327 | 0 | end = p + TERM_COLOR_SIZE; |
328 | | |
329 | | /* escape sequence */ |
330 | 0 | dprint_termc_add(p, end, "\033["); |
331 | | |
332 | 0 | if(f != '_') { |
333 | 0 | if(islower((int)f)) { |
334 | | /* normal font */ |
335 | 0 | dprint_termc_add(p, end, "0;"); |
336 | 0 | } else { |
337 | | /* bold font */ |
338 | 0 | dprint_termc_add(p, end, "1;"); |
339 | 0 | f += 32; |
340 | 0 | } |
341 | 0 | } |
342 | | |
343 | | /* foreground */ |
344 | 0 | switch(f) { |
345 | 0 | case 'x': |
346 | 0 | dprint_termc_add(p, end, "39;"); |
347 | 0 | break; |
348 | 0 | case 's': |
349 | 0 | dprint_termc_add(p, end, "30;"); |
350 | 0 | break; |
351 | 0 | case 'r': |
352 | 0 | dprint_termc_add(p, end, "31;"); |
353 | 0 | break; |
354 | 0 | case 'g': |
355 | 0 | dprint_termc_add(p, end, "32;"); |
356 | 0 | break; |
357 | 0 | case 'y': |
358 | 0 | dprint_termc_add(p, end, "33;"); |
359 | 0 | break; |
360 | 0 | case 'b': |
361 | 0 | dprint_termc_add(p, end, "34;"); |
362 | 0 | break; |
363 | 0 | case 'p': |
364 | 0 | dprint_termc_add(p, end, "35;"); |
365 | 0 | break; |
366 | 0 | case 'c': |
367 | 0 | dprint_termc_add(p, end, "36;"); |
368 | 0 | break; |
369 | 0 | case 'w': |
370 | 0 | dprint_termc_add(p, end, "37;"); |
371 | 0 | break; |
372 | 0 | default: |
373 | 0 | dprint_termc_add(p, end, "39;"); |
374 | 0 | } |
375 | | |
376 | | /* background */ |
377 | 0 | switch(b) { |
378 | 0 | case 'x': |
379 | 0 | dprint_termc_add(p, end, "49"); |
380 | 0 | break; |
381 | 0 | case 's': |
382 | 0 | dprint_termc_add(p, end, "40"); |
383 | 0 | break; |
384 | 0 | case 'r': |
385 | 0 | dprint_termc_add(p, end, "41"); |
386 | 0 | break; |
387 | 0 | case 'g': |
388 | 0 | dprint_termc_add(p, end, "42"); |
389 | 0 | break; |
390 | 0 | case 'y': |
391 | 0 | dprint_termc_add(p, end, "43"); |
392 | 0 | break; |
393 | 0 | case 'b': |
394 | 0 | dprint_termc_add(p, end, "44"); |
395 | 0 | break; |
396 | 0 | case 'p': |
397 | 0 | dprint_termc_add(p, end, "45"); |
398 | 0 | break; |
399 | 0 | case 'c': |
400 | 0 | dprint_termc_add(p, end, "46"); |
401 | 0 | break; |
402 | 0 | case 'w': |
403 | 0 | dprint_termc_add(p, end, "47"); |
404 | 0 | break; |
405 | 0 | default: |
406 | 0 | dprint_termc_add(p, end, "49"); |
407 | 0 | } |
408 | | |
409 | | /* end */ |
410 | 0 | dprint_termc_add(p, end, "m"); |
411 | | |
412 | 0 | obuf->s = term_color; |
413 | 0 | obuf->len = p - term_color; |
414 | 0 | return; |
415 | | |
416 | 0 | error: |
417 | 0 | obuf->s = term_color; |
418 | 0 | term_color[0] = '\0'; |
419 | 0 | obuf->len = 0; |
420 | 0 | } |
421 | | |
422 | | void dprint_color(int level) |
423 | 0 | { |
424 | 0 | str obuf; |
425 | |
|
426 | 0 | if(level < L_MIN || level > L_MAX) |
427 | 0 | return; |
428 | 0 | dprint_term_color(_log_level_colors[level - L_MIN].f, |
429 | 0 | _log_level_colors[level - L_MIN].b, &obuf); |
430 | 0 | fprintf(stderr, "%.*s", obuf.len, obuf.s); |
431 | 0 | } |
432 | | |
433 | | void dprint_color_reset(void) |
434 | 0 | { |
435 | 0 | str obuf; |
436 | |
|
437 | 0 | dprint_term_color('x', 'x', &obuf); |
438 | 0 | fprintf(stderr, "%.*s", obuf.len, obuf.s); |
439 | 0 | } |
440 | | |
441 | | void dprint_color_update(int level, char f, char b) |
442 | 0 | { |
443 | 0 | if(level < L_MIN || level > L_MAX) |
444 | 0 | return; |
445 | 0 | if(f && f != '0') |
446 | 0 | _log_level_colors[level - L_MIN].f = f; |
447 | 0 | if(b && b != '0') |
448 | 0 | _log_level_colors[level - L_MIN].b = b; |
449 | 0 | } |
450 | | |
451 | | |
452 | | /* log_prefix functionality */ |
453 | | str *log_prefix_val = NULL; |
454 | | int log_prefix_mode = 0; |
455 | | static pv_elem_t *log_prefix_pvs = NULL; |
456 | | |
457 | 0 | #define LOG_PREFIX_SIZE 1024 |
458 | | static char log_prefix_buf[LOG_PREFIX_SIZE]; |
459 | | static str log_prefix_str = STR_NULL; |
460 | | |
461 | | void log_init(void) |
462 | 0 | { |
463 | 0 | struct addrinfo hints; |
464 | 0 | struct addrinfo *info = NULL; |
465 | 0 | int gai_result; |
466 | 0 | char hostname[1024]; |
467 | |
|
468 | 0 | hostname[1023] = '\0'; |
469 | 0 | gethostname(hostname, 1023); |
470 | |
|
471 | 0 | memset(&hints, 0, sizeof(hints)); |
472 | 0 | hints.ai_family = AF_UNSPEC; /*either IPV4 or IPV6 */ |
473 | 0 | hints.ai_socktype = SOCK_STREAM; |
474 | 0 | hints.ai_flags = AI_CANONNAME; |
475 | |
|
476 | 0 | if((gai_result = getaddrinfo(hostname, 0, &hints, &info)) != 0) { |
477 | 0 | log_fqdn = "?"; |
478 | 0 | } else if(info == NULL) { |
479 | 0 | log_fqdn = "?"; |
480 | 0 | } else { |
481 | 0 | log_fqdn = strdup(info->ai_canonname); |
482 | 0 | } |
483 | |
|
484 | 0 | if(info != NULL) { |
485 | 0 | freeaddrinfo(info); |
486 | 0 | } |
487 | |
|
488 | 0 | dprint_init_colors(); |
489 | 0 | } |
490 | | |
491 | | void log_prefix_init(void) |
492 | 0 | { |
493 | 0 | str s; |
494 | 0 | if(log_prefix_fmt == NULL) |
495 | 0 | return; |
496 | 0 | s.s = log_prefix_fmt; |
497 | 0 | s.len = strlen(s.s); |
498 | |
|
499 | 0 | if(pv_parse_format(&s, &log_prefix_pvs) < 0) { |
500 | 0 | LM_ERR("wrong format[%s]\n", s.s); |
501 | 0 | return; |
502 | 0 | } |
503 | 0 | } |
504 | | |
505 | | void log_prefix_set(sip_msg_t *msg) |
506 | 0 | { |
507 | 0 | log_callid_set(msg); |
508 | 0 | if(log_prefix_pvs == NULL) |
509 | 0 | return; |
510 | 0 | if(msg == NULL || !IS_SIP_MSG(msg)) { |
511 | 0 | log_prefix_val = NULL; |
512 | 0 | return; |
513 | 0 | } |
514 | 0 | log_prefix_str.s = log_prefix_buf; |
515 | 0 | log_prefix_str.len = LOG_PREFIX_SIZE; |
516 | 0 | if(pv_printf(msg, log_prefix_pvs, log_prefix_str.s, &log_prefix_str.len) |
517 | 0 | < 0) |
518 | 0 | return; |
519 | 0 | if(log_prefix_str.len <= 0) |
520 | 0 | return; |
521 | 0 | log_prefix_val = &log_prefix_str; |
522 | 0 | } |
523 | | |
524 | | /* structured logging */ |
525 | | |
526 | | ksr_slog_f _ksr_slog_func = NULL; |
527 | | |
528 | 0 | #define LOG_CALLID_SIZE 256 |
529 | | static char log_callid_buf[LOG_CALLID_SIZE]; |
530 | | static str log_callid_str = STR_NULL; |
531 | | |
532 | | static int _ksr_slog_json_flags = 0; |
533 | 0 | #define KSR_SLOGJSON_FL_STRIPMSGNL (1 << 0) |
534 | 0 | #define KSR_SLOGJSON_FL_NOLOGNL (1 << 1) |
535 | 0 | #define KSR_SLOGJSON_FL_APPPREFIX (1 << 2) |
536 | 0 | #define KSR_SLOGJSON_FL_NOAPPPREFIXMSG (1 << 3) |
537 | 0 | #define KSR_SLOGJSON_FL_CALLID (1 << 4) |
538 | 0 | #define KSR_SLOGJSON_FL_MSGJSON (1 << 5) |
539 | 0 | #define KSR_SLOGJSON_FL_PRFJSONFLD (1 << 6) |
540 | | |
541 | | |
542 | | #define LOGV_CALLID_STR \ |
543 | 0 | (((_ksr_slog_json_flags & KSR_SLOGJSON_FL_CALLID) \ |
544 | 0 | && (log_callid_str.len > 0)) \ |
545 | 0 | ? log_callid_str.s \ |
546 | 0 | : "") |
547 | | #define LOGV_CALLID_LEN \ |
548 | 0 | (((_ksr_slog_json_flags & KSR_SLOGJSON_FL_CALLID) \ |
549 | 0 | && (log_callid_str.len > 0)) \ |
550 | 0 | ? log_callid_str.len \ |
551 | 0 | : 0) |
552 | | |
553 | | #define KSR_SLOG_SYSLOG_JSON_FMT \ |
554 | 0 | "{ \"level\": \"%s\", \"module\": \"%s\", \"file\": \"%s\"," \ |
555 | 0 | " \"line\": %d, \"function\": \"%s\"%.*s%s%s%.*s%s, \"%smessage\": " \ |
556 | 0 | "%s%.*s%s }%s" |
557 | | |
558 | | #define KSR_SLOG_SYSLOG_JSON_CFMT \ |
559 | 0 | "{ \"level\": \"%s\", \"module\": \"%s\", \"file\": \"%s\"," \ |
560 | 0 | " \"line\": %d, \"function\": \"%s\", \"callid\": \"%.*s\"%s%s%.*s%s, " \ |
561 | 0 | "\"%smessage\": %s%.*s%s }%s" |
562 | | |
563 | | #define KSR_SLOG_SYSLOG_JSON_PFMT \ |
564 | 0 | "{ \"" NAME ".level\": \"%s\", \"" NAME ".module\": \"%s\", \"" NAME \ |
565 | 0 | ".file\": \"%s\"," \ |
566 | 0 | " \"" NAME ".line\": %d, \"" NAME \ |
567 | 0 | ".function\": \"%s\"%.*s%s%s%.*s%s, \"%smessage\": %s%.*s%s }%s" |
568 | | |
569 | | #define KSR_SLOG_SYSLOG_JSON_CPFMT \ |
570 | 0 | "{ \"" NAME ".level\": \"%s\", \"" NAME ".module\": \"%s\", \"" NAME \ |
571 | 0 | ".file\": \"%s\"," \ |
572 | 0 | " \"" NAME ".line\": %d, \"" NAME ".function\": \"%s\", \"" NAME \ |
573 | 0 | ".callid\": \"%.*s\"%s%s%.*s%s," \ |
574 | 0 | " \"%smessage\": %s%.*s%s }%s" |
575 | | |
576 | | #define KSR_SLOG_STDERR_JSON_FMT \ |
577 | 0 | "{ \"idx\": %d, \"pid\": %d, \"level\": \"%s\"," \ |
578 | 0 | " \"module\": \"%s\", \"file\": \"%s\"," \ |
579 | 0 | " \"line\": %d, \"function\": \"%s\"%.*s%s%s%.*s%s, \"%smessage\": " \ |
580 | 0 | "%s%.*s%s }%s" |
581 | | |
582 | | #define KSR_SLOG_STDERR_JSON_CFMT \ |
583 | 0 | "{ \"idx\": %d, \"pid\": %d, \"level\": \"%s\"," \ |
584 | 0 | " \"module\": \"%s\", \"file\": \"%s\"," \ |
585 | 0 | " \"line\": %d, \"function\": \"%s\", \"callid\": \"%.*s\"%s%s%.*s%s, " \ |
586 | 0 | "\"%smessage\": %s%.*s%s }%s" |
587 | | |
588 | | #define KSR_SLOG_STDERR_JSON_PFMT \ |
589 | 0 | "{ \"" NAME ".idx\": %d, \"" NAME ".pid\": %d, \"" NAME \ |
590 | 0 | ".level\": \"%s\"," \ |
591 | 0 | " \"" NAME ".module\": \"%s\", \"" NAME ".file\": \"%s\"," \ |
592 | 0 | " \"" NAME ".line\": %d, \"" NAME \ |
593 | 0 | ".function\": \"%s\"%.*s\"%s%s%.*s%s, \"%smessage\": %s%.*s%s }%s" |
594 | | |
595 | | #define KSR_SLOG_STDERR_JSON_CPFMT \ |
596 | 0 | "{ \"" NAME ".idx\": %d, \"" NAME ".pid\": %d, \"" NAME \ |
597 | 0 | ".level\": \"%s\"," \ |
598 | 0 | " \"" NAME ".module\": \"%s\", \"" NAME ".file\": \"%s\"," \ |
599 | 0 | " \"" NAME ".line\": %d, \"" NAME ".function\": \"%s\", \"" NAME \ |
600 | 0 | ".callid\": \"%.*s\"%s%s%.*s%s," \ |
601 | 0 | " \"%smessage\": %s%.*s%s }%s" |
602 | | |
603 | | #ifdef HAVE_PTHREAD |
604 | | #define KSR_SLOG_JSON_CEEFMT_TID ",\"tid\":%ju" |
605 | | #else |
606 | | #define KSR_SLOG_JSON_CEEFMT_TID "" |
607 | | #endif |
608 | | #define KSR_SLOG_JSON_CEEFMT \ |
609 | 0 | "{\"time\":\"%s.%09luZ\",\"proc\":{\"id\":\"%d\"" KSR_SLOG_JSON_CEEFMT_TID \ |
610 | 0 | "},\"pri\":\"%s\",\"subsys\":\"%s\"," \ |
611 | 0 | "\"file\":{\"name\":\"%s\",\"line\":%d},\"native\":{\"function\":\"%s\"}," \ |
612 | 0 | "\"msg\":%s%.*s%s," \ |
613 | 0 | "\"pname\":\"%s\",\"appname\":\"%s\",\"hostname\":\"%s\"}%s" |
614 | | |
615 | 0 | #define KSR_SLOG_SYSLOG_JSON_CEEFMT "@cee: " KSR_SLOG_JSON_CEEFMT |
616 | | |
617 | 0 | #define KSR_SLOG_STDERR_JSON_CEEFMT KSR_SLOG_JSON_CEEFMT |
618 | | |
619 | | void ksr_slog_json(ksr_logdata_t *kld, const char *format, ...) |
620 | 0 | { |
621 | 0 | va_list arglist; |
622 | 0 | #define KSR_SLOG_MAX_SIZE 32 * 1024 |
623 | 0 | char obuf[KSR_SLOG_MAX_SIZE]; |
624 | 0 | int n; |
625 | 0 | str s_in = STR_NULL; |
626 | 0 | str s_out = STR_NULL; |
627 | 0 | int emode = 0; |
628 | 0 | char *prefmsg; |
629 | 0 | const char *efmt; |
630 | 0 | const char *sfmt; |
631 | 0 | #define ISO8601_BUF_SIZE 32 |
632 | 0 | char iso8601buf[ISO8601_BUF_SIZE + 1]; |
633 | 0 | struct timespec _tp; |
634 | 0 | struct tm _tm; |
635 | 0 | char *smb = "\""; |
636 | 0 | char *sme = "\""; |
637 | 0 | char *pmb = "\""; |
638 | 0 | char *pme = "\""; |
639 | 0 | char *prname = ", \"" NAME ".logprefix\": "; |
640 | |
|
641 | 0 | va_start(arglist, format); |
642 | 0 | n = vsnprintf( |
643 | 0 | obuf + s_in.len, KSR_SLOG_MAX_SIZE - s_in.len, format, arglist); |
644 | 0 | if(n < 0 || n >= KSR_SLOG_MAX_SIZE - s_in.len) { |
645 | 0 | va_end(arglist); |
646 | 0 | goto error; |
647 | 0 | } |
648 | 0 | s_in.len += n; |
649 | 0 | va_end(arglist); |
650 | |
|
651 | 0 | s_in.s = obuf; |
652 | 0 | if(_ksr_slog_json_flags & KSR_SLOGJSON_FL_STRIPMSGNL) { |
653 | 0 | if(s_in.s[s_in.len - 1] == '\n') { |
654 | 0 | s_in.len--; |
655 | 0 | } |
656 | 0 | } |
657 | |
|
658 | 0 | if((!log_cee) && (_ksr_slog_json_flags & KSR_SLOGJSON_FL_MSGJSON)) { |
659 | 0 | if((s_in.len > 1) && (s_in.s[0] == '{') |
660 | 0 | && (s_in.s[s_in.len - 1] == '}')) { |
661 | 0 | s_out = s_in; |
662 | 0 | smb = ""; |
663 | 0 | sme = ""; |
664 | 0 | } else { |
665 | 0 | smb = "{ \"text\": \""; |
666 | 0 | sme = "\" }"; |
667 | 0 | } |
668 | 0 | if((log_prefix_val != NULL) && (log_prefix_val->len > 1) |
669 | 0 | && (log_prefix_val->s[0] == '{') |
670 | 0 | && (log_prefix_val->s[log_prefix_val->len - 1] == '}')) { |
671 | 0 | pmb = ""; |
672 | 0 | pme = ""; |
673 | 0 | } else { |
674 | 0 | pmb = "{ \"text\": \""; |
675 | 0 | pme = "\" }"; |
676 | 0 | } |
677 | 0 | } |
678 | |
|
679 | 0 | if(s_out.s == NULL) { |
680 | 0 | ksr_str_json_escape(&s_in, &s_out, &emode); |
681 | 0 | if(s_out.s == NULL) { |
682 | 0 | goto error; |
683 | 0 | } |
684 | 0 | } |
685 | | |
686 | 0 | if(_ksr_slog_json_flags & KSR_SLOGJSON_FL_APPPREFIX) { |
687 | 0 | if(_ksr_slog_json_flags & KSR_SLOGJSON_FL_NOAPPPREFIXMSG) { |
688 | 0 | prefmsg = ""; |
689 | 0 | } else { |
690 | 0 | prefmsg = NAME "."; |
691 | 0 | } |
692 | 0 | prname = ", \"" NAME ".logprefix\": "; |
693 | 0 | if(_ksr_slog_json_flags & KSR_SLOGJSON_FL_CALLID) { |
694 | 0 | efmt = KSR_SLOG_STDERR_JSON_CPFMT; |
695 | 0 | sfmt = KSR_SLOG_SYSLOG_JSON_CPFMT; |
696 | 0 | } else { |
697 | 0 | efmt = KSR_SLOG_STDERR_JSON_PFMT; |
698 | 0 | sfmt = KSR_SLOG_SYSLOG_JSON_PFMT; |
699 | 0 | } |
700 | 0 | } else { |
701 | 0 | prefmsg = ""; |
702 | 0 | prname = ", \"logprefix\": "; |
703 | 0 | if(_ksr_slog_json_flags & KSR_SLOGJSON_FL_CALLID) { |
704 | 0 | efmt = KSR_SLOG_STDERR_JSON_CFMT; |
705 | 0 | sfmt = KSR_SLOG_SYSLOG_JSON_CFMT; |
706 | 0 | } else { |
707 | 0 | efmt = KSR_SLOG_STDERR_JSON_FMT; |
708 | 0 | sfmt = KSR_SLOG_SYSLOG_JSON_FMT; |
709 | 0 | } |
710 | 0 | } |
711 | 0 | if((!log_cee) && (_ksr_slog_json_flags & KSR_SLOGJSON_FL_PRFJSONFLD)) { |
712 | 0 | if((log_prefix_val == NULL) || (log_prefix_val->len <= 0) |
713 | 0 | || ((log_prefix_val->len > 1) |
714 | 0 | && (log_prefix_val->s[0] == ','))) { |
715 | 0 | prname = ""; |
716 | 0 | pmb = ""; |
717 | 0 | pme = ""; |
718 | 0 | } |
719 | 0 | } |
720 | 0 | ksr_clock_gettime(&_tp); |
721 | 0 | gmtime_r(&_tp.tv_sec, &_tm); |
722 | 0 | strftime(iso8601buf, ISO8601_BUF_SIZE, "%FT%T", &_tm); |
723 | 0 | if(unlikely(log_stderr)) { |
724 | 0 | if(unlikely(log_cee)) { |
725 | 0 | fprintf(stderr, KSR_SLOG_STDERR_JSON_CEEFMT, iso8601buf, |
726 | 0 | _tp.tv_nsec, my_pid(), |
727 | 0 | #ifdef HAVE_PTHREAD |
728 | 0 | (uintmax_t)pthread_self(), |
729 | 0 | #endif |
730 | 0 | kld->v_lname, kld->v_mname, kld->v_fname, kld->v_fline, |
731 | 0 | kld->v_func, smb, s_out.len, s_out.s, sme, "kamailio", |
732 | 0 | log_name != 0 ? log_name : "kamailio", log_fqdn, |
733 | 0 | (_ksr_slog_json_flags & KSR_SLOGJSON_FL_NOLOGNL) ? "" |
734 | 0 | : "\n"); |
735 | 0 | } else { |
736 | 0 | if(unlikely(log_color)) |
737 | 0 | dprint_color(kld->v_level); |
738 | 0 | fprintf(stderr, efmt, process_no, my_pid(), kld->v_lname, |
739 | 0 | kld->v_mname, kld->v_fname, kld->v_fline, kld->v_func, |
740 | 0 | LOGV_CALLID_LEN, LOGV_CALLID_STR, prname, pmb, |
741 | 0 | LOGV_PREFIX_LEN, LOGV_PREFIX_STR, pme, prefmsg, smb, |
742 | 0 | s_out.len, s_out.s, sme, |
743 | 0 | (_ksr_slog_json_flags & KSR_SLOGJSON_FL_NOLOGNL) ? "" |
744 | 0 | : "\n"); |
745 | 0 | if(unlikely(log_color)) |
746 | 0 | dprint_color_reset(); |
747 | 0 | } |
748 | 0 | } else { |
749 | 0 | if(unlikely(log_cee)) { |
750 | 0 | _km_log_func(kld->v_facility, KSR_SLOG_SYSLOG_JSON_CEEFMT, |
751 | 0 | iso8601buf, _tp.tv_nsec, my_pid(), |
752 | 0 | #ifdef HAVE_PTHREAD |
753 | 0 | pthread_self(), |
754 | 0 | #endif |
755 | 0 | kld->v_lname, kld->v_mname, kld->v_fname, kld->v_fline, |
756 | 0 | kld->v_func, smb, s_out.len, s_out.s, sme, "kamailio", |
757 | 0 | log_name != 0 ? log_name : "kamailio", log_fqdn, |
758 | 0 | (_ksr_slog_json_flags & KSR_SLOGJSON_FL_NOLOGNL) ? "" |
759 | 0 | : "\n"); |
760 | 0 | } else { |
761 | 0 | _km_log_func(kld->v_facility, sfmt, kld->v_lname, kld->v_mname, |
762 | 0 | kld->v_fname, kld->v_fline, kld->v_func, LOGV_CALLID_LEN, |
763 | 0 | LOGV_CALLID_STR, prname, pmb, LOGV_PREFIX_LEN, |
764 | 0 | LOGV_PREFIX_STR, pme, prefmsg, smb, s_out.len, s_out.s, sme, |
765 | 0 | (_ksr_slog_json_flags & KSR_SLOGJSON_FL_NOLOGNL) ? "" |
766 | 0 | : "\n"); |
767 | 0 | } |
768 | 0 | } |
769 | 0 | if(emode && s_out.s) { |
770 | 0 | free(s_out.s); |
771 | 0 | } |
772 | 0 | return; |
773 | 0 | error: |
774 | 0 | return; |
775 | 0 | } |
776 | | |
777 | | void ksr_slog_init(char *ename) |
778 | 0 | { |
779 | 0 | char *p; |
780 | 0 | int elen = 0; |
781 | |
|
782 | 0 | if(!ename) { |
783 | 0 | return; |
784 | 0 | } |
785 | | |
786 | 0 | p = strchr(ename, ':'); |
787 | 0 | if(p) { |
788 | 0 | elen = p - ename; |
789 | 0 | } else { |
790 | 0 | elen = strlen(ename); |
791 | 0 | } |
792 | |
|
793 | 0 | if((elen == 4) && (strncasecmp(ename, "json", 4) == 0)) { |
794 | 0 | _km_log_engine_type = "json"; |
795 | 0 | _ksr_slog_func = &ksr_slog_json; |
796 | 0 | if(p) { |
797 | 0 | _km_log_engine_data = p + 1; |
798 | 0 | while(*p) { |
799 | 0 | switch(*p) { |
800 | 0 | case 'a': |
801 | 0 | _ksr_slog_json_flags |= KSR_SLOGJSON_FL_APPPREFIX; |
802 | 0 | break; |
803 | 0 | case 'A': |
804 | 0 | _ksr_slog_json_flags |= KSR_SLOGJSON_FL_NOAPPPREFIXMSG; |
805 | 0 | break; |
806 | 0 | case 'c': |
807 | 0 | _ksr_slog_json_flags |= KSR_SLOGJSON_FL_CALLID; |
808 | 0 | break; |
809 | 0 | case 'j': |
810 | 0 | _ksr_slog_json_flags |= KSR_SLOGJSON_FL_MSGJSON; |
811 | 0 | break; |
812 | 0 | case 'M': |
813 | 0 | _ksr_slog_json_flags |= KSR_SLOGJSON_FL_STRIPMSGNL; |
814 | 0 | break; |
815 | 0 | case 'N': |
816 | 0 | _ksr_slog_json_flags |= KSR_SLOGJSON_FL_NOLOGNL; |
817 | 0 | break; |
818 | 0 | case 'p': |
819 | 0 | _ksr_slog_json_flags |= KSR_SLOGJSON_FL_PRFJSONFLD; |
820 | 0 | break; |
821 | 0 | case 'U': |
822 | 0 | log_cee = 1; |
823 | 0 | break; |
824 | 0 | } |
825 | 0 | p++; |
826 | 0 | } |
827 | 0 | } |
828 | 0 | } |
829 | 0 | } |
830 | | |
831 | | static void log_callid_set(sip_msg_t *msg) |
832 | 0 | { |
833 | 0 | if(!(_ksr_slog_json_flags & KSR_SLOGJSON_FL_CALLID)) { |
834 | 0 | return; |
835 | 0 | } |
836 | 0 | if(msg == NULL) { |
837 | 0 | log_callid_str.len = 0; |
838 | 0 | log_callid_str.s = NULL; |
839 | 0 | return; |
840 | 0 | } |
841 | 0 | if(msg->callid == NULL |
842 | 0 | && ((parse_headers(msg, HDR_CALLID_F, 0) == -1) |
843 | 0 | || (msg->callid == NULL))) { |
844 | 0 | log_callid_str.len = 0; |
845 | 0 | log_callid_str.s = NULL; |
846 | 0 | return; |
847 | 0 | } |
848 | 0 | if(msg->callid->body.len >= LOG_CALLID_SIZE) { |
849 | 0 | log_callid_str.len = 0; |
850 | 0 | log_callid_str.s = NULL; |
851 | 0 | return; |
852 | 0 | } |
853 | 0 | log_callid_str.len = msg->callid->body.len; |
854 | 0 | memcpy(log_callid_buf, msg->callid->body.s, msg->callid->body.len); |
855 | 0 | log_callid_str.s = log_callid_buf; |
856 | 0 | log_callid_str.s[log_callid_str.len] = '\0'; |
857 | 0 | } |