Line | Count | Source (jump to first uncovered line) |
1 | | /** |
2 | | * Copyright (C) 2001-2003 FhG Fokus |
3 | | * |
4 | | * This file is part of opensips, a free SIP server. |
5 | | * |
6 | | * opensips is free software; you can redistribute it and/or modify |
7 | | * it under the terms of the GNU General Public License as published by |
8 | | * the Free Software Foundation; either version 2 of the License, or |
9 | | * (at your option) any later version |
10 | | * |
11 | | * opensips is distributed in the hope that it will be useful, |
12 | | * but WITHOUT ANY WARRANTY; without even the implied warranty of |
13 | | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the |
14 | | * GNU General Public License for more details. |
15 | | * |
16 | | * You should have received a copy of the GNU General Public License |
17 | | * along with this program; if not, write to the Free Software |
18 | | * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA |
19 | | */ |
20 | | |
21 | | #include <stdio.h> |
22 | | #include <string.h> |
23 | | #include <stdlib.h> |
24 | | #include <sys/types.h> |
25 | | #include <sys/ipc.h> |
26 | | #include <unistd.h> |
27 | | #include <fcntl.h> |
28 | | #include <time.h> |
29 | | #include <ctype.h> |
30 | | |
31 | | #include "sr_module.h" |
32 | | #include "dprint.h" |
33 | | #include "error.h" |
34 | | #include "socket_info.h" |
35 | | #include "mem/mem.h" |
36 | | #include "xlog.h" |
37 | | |
38 | | #include "pvar.h" |
39 | | #include "trace_api.h" |
40 | | |
41 | 0 | #define XLOG_TRACE_API_MODULE "proto_hep" |
42 | | #define XLOG_CORRELATION_MAGIC "XLOGCORR" |
43 | | |
44 | | |
45 | | |
46 | | char *log_buf = NULL; |
47 | | |
48 | | int xlog_buf_size = 4096; |
49 | | int xlog_force_color = 0; |
50 | | |
51 | | /* the log level used when printing xlog messages */ |
52 | | int xlog_print_level = L_NOTICE; |
53 | | |
54 | | /* the logging level/threshold for filtering the xlog messages for printing */ |
55 | | static int xlog_level_default = L_NOTICE; |
56 | | static int xlog_level_local = L_NOTICE; |
57 | | static int *xlog_level_shared = NULL; |
58 | | |
59 | | /* current logging level for this process. |
60 | | * During init it points the 'xlog_level_default' in order to store the |
61 | | * original configured value |
62 | | * During runtime it may point to: |
63 | | * - xlog_level_shared - the shared xlog level between all procs |
64 | | * - &xlog_level_local - for a per-proc changed xlog level |
65 | | */ |
66 | | int *xlog_level = &xlog_level_default; |
67 | | |
68 | | /* id with which xlog will be identified by siptrace module |
69 | | * and will identify an xlog tracing packet */ |
70 | | int xlog_proto_id; |
71 | | /* tracing module api */ |
72 | | static trace_proto_t tprot; |
73 | | |
74 | | /* xlog string identifier */ |
75 | | static const char* xlog_id_s="xlog"; |
76 | | |
77 | | #define is_xlog_printable(_level) \ |
78 | 0 | (((int)(*xlog_level)) >= ((int)(_level))) |
79 | | |
80 | | |
81 | | void set_shared_xlog_level(int new_level) |
82 | 0 | { |
83 | | /* do not accept setting as time the xlog_level still points to the |
84 | | * starting/default holder as we will loose the original value */ |
85 | 0 | if (xlog_level==&xlog_level_default) |
86 | 0 | return; |
87 | | |
88 | 0 | *xlog_level_shared = new_level; |
89 | 0 | } |
90 | | |
91 | | |
92 | | void set_local_xlog_level(int new_level) |
93 | 0 | { |
94 | | /* do not accept setting as time the xlog_level still points to the |
95 | | * starting/default holder as we will loose the original value */ |
96 | 0 | if (xlog_level==&xlog_level_default) |
97 | 0 | return; |
98 | | |
99 | 0 | xlog_level_local = new_level; |
100 | 0 | xlog_level = &xlog_level_local; |
101 | 0 | } |
102 | | |
103 | | |
104 | | void reset_xlog_level(void) |
105 | 0 | { |
106 | 0 | if (xlog_level==&xlog_level_default) |
107 | 0 | return; /* still init, very unlikely */ |
108 | | |
109 | 0 | if (xlog_level==&xlog_level_local) { |
110 | | /* points a local/per-proc xlog level hodler, |
111 | | * so reset it to the shared value */ |
112 | 0 | xlog_level = xlog_level_shared; |
113 | 0 | return; |
114 | 0 | } |
115 | | |
116 | | /* points to the shared holder, so reset the shred value */ |
117 | 0 | *xlog_level_shared = xlog_level_default; |
118 | 0 | } |
119 | | |
120 | | |
121 | | static int buf_init(void) |
122 | 0 | { |
123 | 0 | LM_DBG("initializing...\n"); |
124 | 0 | log_buf = (char*)pkg_malloc((xlog_buf_size+1)*sizeof(char)); |
125 | 0 | if(log_buf==NULL) |
126 | 0 | { |
127 | 0 | LM_ERR("no pkg memory left\n"); |
128 | 0 | return -1; |
129 | 0 | } |
130 | 0 | return 0; |
131 | 0 | } |
132 | | |
133 | | |
134 | | int init_xlog(void) |
135 | 0 | { |
136 | 0 | if (log_buf == NULL) { |
137 | 0 | if (buf_init()) { |
138 | 0 | LM_ERR("Cannot print message!\n"); |
139 | 0 | return -1; |
140 | 0 | } |
141 | 0 | } |
142 | | |
143 | 0 | xlog_level_shared = (int*)shm_malloc(sizeof(int)); |
144 | 0 | if (xlog_level_shared==NULL) { |
145 | 0 | LM_ERR("failed to allocate shared holder for xlog\n"); |
146 | 0 | return -1; |
147 | 0 | } |
148 | 0 | xlog_level = xlog_level_shared; |
149 | 0 | *xlog_level = xlog_level_default; |
150 | |
|
151 | 0 | if (register_trace_type) |
152 | 0 | xlog_proto_id = register_trace_type((char *)xlog_id_s); |
153 | |
|
154 | 0 | memset(&tprot, 0, sizeof(trace_proto_t)); |
155 | 0 | if (global_trace_api) { |
156 | 0 | memcpy(&tprot, global_trace_api, sizeof(trace_proto_t)); |
157 | 0 | } else { |
158 | 0 | if (trace_prot_bind(XLOG_TRACE_API_MODULE, &tprot)) { |
159 | 0 | LM_DBG("failed to load trace protocol!\n"); |
160 | 0 | } |
161 | 0 | } |
162 | | |
163 | |
|
164 | 0 | return 0; |
165 | 0 | } |
166 | | |
167 | | |
168 | | static inline void add_xlog_data(trace_message message, void* param) |
169 | 0 | { |
170 | 0 | str str_level; |
171 | 0 | xl_trace_t* xtrace_param = param; |
172 | 0 | static str sip_str = str_init("sip"); |
173 | | |
174 | |
|
175 | 0 | switch (*xlog_level) { |
176 | 0 | case L_ALERT: |
177 | 0 | str_level.s = DP_ALERT_TEXT; break; |
178 | 0 | case L_CRIT: |
179 | 0 | str_level.s = DP_CRIT_TEXT; break; |
180 | 0 | case L_ERR: |
181 | 0 | str_level.s = DP_ERR_TEXT; break; |
182 | 0 | case L_WARN: |
183 | 0 | str_level.s = DP_WARN_TEXT; break; |
184 | 0 | case L_NOTICE: |
185 | 0 | str_level.s = DP_NOTICE_TEXT; break; |
186 | 0 | case L_INFO: |
187 | 0 | str_level.s = DP_INFO_TEXT; break; |
188 | 0 | case L_DBG: |
189 | 0 | str_level.s = DP_DBG_TEXT; |
190 | 0 | str_level.len = sizeof(DP_DBG_TEXT) - 2; |
191 | 0 | break; |
192 | 0 | default: |
193 | 0 | LM_BUG("Unexpected log level [%d]\n", xlog_print_level); |
194 | 0 | return; |
195 | 0 | } |
196 | | |
197 | | /* remove ':' after each level */ |
198 | 0 | str_level.len = strlen(str_level.s) - 1; |
199 | |
|
200 | 0 | tprot.add_payload_part( message, "Event", &str_level); |
201 | |
|
202 | 0 | if ( !xtrace_param ) |
203 | 0 | return; |
204 | | |
205 | 0 | tprot.add_payload_part( message, "text", &xtrace_param->buf); |
206 | |
|
207 | 0 | if (xtrace_param->msg && xtrace_param->msg->callid) |
208 | 0 | tprot.add_extra_correlation( message, &sip_str, &xtrace_param->msg->callid->body ); |
209 | 0 | } |
210 | | |
211 | | static inline int trace_xlog(struct sip_msg* msg, char* buf, int len) |
212 | 0 | { |
213 | 0 | struct modify_trace mod_p; |
214 | 0 | xl_trace_t xtrace_param; |
215 | 0 | str correlation_str; |
216 | 0 | union sockaddr_union su; |
217 | |
|
218 | 0 | if (msg == NULL || buf == NULL) { |
219 | 0 | LM_ERR("bad input!\n"); |
220 | 0 | return -1; |
221 | 0 | } |
222 | | |
223 | | /* xlog not traced; exit... */ |
224 | 0 | if (!check_is_traced || check_is_traced(xlog_proto_id) == 0) |
225 | 0 | return 0; |
226 | | |
227 | 0 | mod_p.mod_f = add_xlog_data; |
228 | 0 | xtrace_param.msg = msg; |
229 | |
|
230 | 0 | xtrace_param.buf.s = buf; |
231 | 0 | xtrace_param.buf.len = len; |
232 | |
|
233 | 0 | mod_p.param = &xtrace_param; |
234 | |
|
235 | 0 | if (msg->callid && msg->callid->body.len) { |
236 | 0 | correlation_str = msg->callid->body; |
237 | 0 | } else { |
238 | 0 | correlation_str.s = "<null>"; |
239 | 0 | correlation_str.len = 6; |
240 | 0 | } |
241 | |
|
242 | 0 | if (msg->rcv.bind_address && msg->rcv.bind_address->port_no) |
243 | | /* coverity[check_return] - CID #211391 */ |
244 | 0 | init_su( &su, &msg->rcv.bind_address->address, |
245 | 0 | msg->rcv.bind_address->port_no); |
246 | 0 | else |
247 | 0 | su.s.sa_family = 0; |
248 | |
|
249 | 0 | if (sip_context_trace(xlog_proto_id, |
250 | 0 | su.s.sa_family ? &su : NULL /*src*/, su.s.sa_family ? &su : NULL /*dst*/, |
251 | 0 | 0, IPPROTO_TCP, |
252 | 0 | &correlation_str, &mod_p) < 0) { |
253 | 0 | LM_ERR("failed to trace xlog message!\n"); |
254 | 0 | return -1; |
255 | 0 | } |
256 | | |
257 | 0 | return 0; |
258 | 0 | } |
259 | | |
260 | | int xl_print_log(struct sip_msg* msg, pv_elem_p list, int *len) |
261 | 0 | { |
262 | 0 | if (pv_printf(msg, list, log_buf, len) < 0) |
263 | 0 | return -1; |
264 | | |
265 | 0 | if (trace_xlog(msg, log_buf, *len) < 0) { |
266 | 0 | LM_ERR("failed to trace xlog message!\n"); |
267 | 0 | return -2; |
268 | 0 | } |
269 | | |
270 | 0 | return 1; |
271 | 0 | } |
272 | | |
273 | | |
274 | | int xlog_2(struct sip_msg* msg, char* lev, char* frm) |
275 | 0 | { |
276 | 0 | int log_len, ret; |
277 | 0 | long level; |
278 | 0 | xl_level_p xlp; |
279 | 0 | pv_value_t value; |
280 | |
|
281 | 0 | xlp = (xl_level_t*)(void*)lev; |
282 | 0 | if(xlp->type==1) |
283 | 0 | { |
284 | 0 | if(pv_get_spec_value(msg, &xlp->v.sp, &value)!=0 |
285 | 0 | || value.flags&PV_VAL_NULL || !(value.flags&PV_VAL_INT)) |
286 | 0 | { |
287 | 0 | LM_ERR("invalid log level value [%d]\n", value.flags); |
288 | 0 | return -1; |
289 | 0 | } |
290 | 0 | level = (long)value.ri; |
291 | 0 | } else { |
292 | 0 | level = xlp->v.level; |
293 | 0 | } |
294 | | |
295 | 0 | if(!is_xlog_printable((int)level)) |
296 | 0 | return 1; |
297 | | |
298 | 0 | log_len = xlog_buf_size; |
299 | |
|
300 | 0 | ret = xl_print_log(msg, (pv_elem_t*)(void*)frm, &log_len); |
301 | 0 | if (ret == -1) { |
302 | 0 | LM_ERR("global print buffer too small, increase 'xlog_buf_size'\n"); |
303 | 0 | return -1; |
304 | 0 | } |
305 | | |
306 | | /* set the xlog as log level to trick "LM_GEN" */ |
307 | 0 | set_proc_log_level( *xlog_level ); |
308 | | |
309 | | /* log_buf[log_len] = '\0'; */ |
310 | 0 | LM_GEN1((int)level, "%.*s", log_len, log_buf); |
311 | | |
312 | 0 | reset_proc_log_level(); |
313 | |
|
314 | 0 | return ret; |
315 | 0 | } |
316 | | |
317 | | |
318 | | int xlog_1(struct sip_msg* msg, char* frm) |
319 | 0 | { |
320 | 0 | int log_len, ret; |
321 | |
|
322 | 0 | if(!is_xlog_printable(xlog_print_level)) |
323 | 0 | return 1; |
324 | | |
325 | 0 | log_len = xlog_buf_size; |
326 | |
|
327 | 0 | ret = xl_print_log(msg, (pv_elem_t*)(void*)frm, &log_len); |
328 | 0 | if (ret == -1) { |
329 | 0 | LM_ERR("global print buffer too small, increase 'xlog_buf_size'\n"); |
330 | 0 | return -1; |
331 | 0 | } |
332 | | |
333 | | /* set the xlog as log level to trick "LM_GEN" */ |
334 | 0 | set_proc_log_level( *xlog_level ); |
335 | | |
336 | | /* log_buf[log_len] = '\0'; */ |
337 | 0 | LM_GEN1(xlog_print_level, "%.*s", log_len, log_buf); |
338 | | |
339 | 0 | reset_proc_log_level(); |
340 | |
|
341 | 0 | return ret; |
342 | 0 | } |
343 | | |
344 | | /** |
345 | | */ |
346 | | int xdbg(struct sip_msg* msg, char* frm) |
347 | 0 | { |
348 | 0 | int log_len, ret; |
349 | |
|
350 | 0 | if(!is_xlog_printable(L_DBG)) |
351 | 0 | return 1; |
352 | | |
353 | 0 | log_len = xlog_buf_size; |
354 | |
|
355 | 0 | ret = xl_print_log(msg, (pv_elem_t*)(void*)frm, &log_len); |
356 | 0 | if (ret == -1) { |
357 | 0 | LM_ERR("global print buffer too small, increase 'xlog_buf_size'\n"); |
358 | 0 | return -1; |
359 | 0 | } |
360 | | |
361 | | /* set the xlog as log level to trick "LM_GEN" */ |
362 | 0 | set_proc_log_level( *xlog_level ); |
363 | | |
364 | | /* log_buf[log_len] = '\0'; */ |
365 | 0 | LM_GEN1(L_DBG, "%.*s", log_len, log_buf); |
366 | | |
367 | 0 | reset_proc_log_level(); |
368 | |
|
369 | 0 | return ret; |
370 | 0 | } |
371 | | |
372 | | int pv_parse_color_name(pv_spec_p sp, const str *in) |
373 | 0 | { |
374 | |
|
375 | 0 | if(in==NULL || in->s==NULL || sp==NULL) |
376 | 0 | return -1; |
377 | | |
378 | 0 | if(in->len != 2) |
379 | 0 | { |
380 | 0 | LM_ERR("color name must have two chars\n"); |
381 | 0 | return -1; |
382 | 0 | } |
383 | | |
384 | | /* foreground */ |
385 | 0 | switch(in->s[0]) |
386 | 0 | { |
387 | 0 | case 'x': |
388 | 0 | case 's': case 'r': case 'g': |
389 | 0 | case 'y': case 'b': case 'p': |
390 | 0 | case 'c': case 'w': case 'S': |
391 | 0 | case 'R': case 'G': case 'Y': |
392 | 0 | case 'B': case 'P': case 'C': |
393 | 0 | case 'W': |
394 | 0 | break; |
395 | 0 | default: |
396 | 0 | goto error; |
397 | 0 | } |
398 | | |
399 | | /* background */ |
400 | 0 | switch(in->s[1]) |
401 | 0 | { |
402 | 0 | case 'x': |
403 | 0 | case 's': case 'r': case 'g': |
404 | 0 | case 'y': case 'b': case 'p': |
405 | 0 | case 'c': case 'w': |
406 | 0 | break; |
407 | 0 | default: |
408 | 0 | goto error; |
409 | 0 | } |
410 | | |
411 | 0 | sp->pvp.pvn.type = PV_NAME_INTSTR; |
412 | 0 | sp->pvp.pvn.u.isname.type = AVP_NAME_STR; |
413 | 0 | sp->pvp.pvn.u.isname.name.s = *in; |
414 | |
|
415 | 0 | sp->getf = pv_get_color; |
416 | | |
417 | | /* force the color PV type */ |
418 | 0 | sp->type = PVT_COLOR; |
419 | 0 | return 0; |
420 | 0 | error: |
421 | 0 | LM_ERR("invalid color name\n"); |
422 | 0 | return -1; |
423 | 0 | } |
424 | | |
425 | 0 | #define COL_BUF 10 |
426 | | |
427 | | #define append_sstring(p, end, s) \ |
428 | 0 | do{\ |
429 | 0 | if ((p)+(sizeof(s)-1)<=(end)){\ |
430 | 0 | memcpy((p), s, sizeof(s)-1); \ |
431 | 0 | (p)+=sizeof(s)-1; \ |
432 | 0 | }else{ \ |
433 | 0 | /* overflow */ \ |
434 | 0 | LM_ERR("append_sstring overflow\n"); \ |
435 | 0 | goto error;\ |
436 | 0 | } \ |
437 | 0 | } while(0) |
438 | | |
439 | | |
440 | | int pv_get_color(struct sip_msg *msg, pv_param_t *param, |
441 | | pv_value_t *res) |
442 | 0 | { |
443 | 0 | static char color[COL_BUF]; |
444 | 0 | char* p; |
445 | 0 | char* end; |
446 | 0 | str s; |
447 | |
|
448 | 0 | if(xlog_force_color==0) |
449 | 0 | { |
450 | 0 | s.s = ""; |
451 | 0 | s.len = 0; |
452 | 0 | return pv_get_strval(msg, param, res, &s); |
453 | 0 | } |
454 | | |
455 | 0 | p = color; |
456 | 0 | end = p + COL_BUF; |
457 | | |
458 | | /* excape sequenz */ |
459 | 0 | append_sstring(p, end, "\033["); |
460 | | |
461 | 0 | if(param->pvn.u.isname.name.s.s[0]!='_') |
462 | 0 | { |
463 | 0 | if (islower((int)param->pvn.u.isname.name.s.s[0])) |
464 | 0 | { |
465 | | /* normal font */ |
466 | 0 | append_sstring(p, end, "0;"); |
467 | 0 | } else { |
468 | | /* bold font */ |
469 | 0 | append_sstring(p, end, "1;"); |
470 | 0 | param->pvn.u.isname.name.s.s[0] += 32; |
471 | 0 | } |
472 | 0 | } |
473 | | |
474 | | /* foreground */ |
475 | 0 | switch(param->pvn.u.isname.name.s.s[0]) |
476 | 0 | { |
477 | 0 | case 'x': |
478 | 0 | append_sstring(p, end, "39;"); |
479 | 0 | break; |
480 | 0 | case 's': |
481 | 0 | append_sstring(p, end, "30;"); |
482 | 0 | break; |
483 | 0 | case 'r': |
484 | 0 | append_sstring(p, end, "31;"); |
485 | 0 | break; |
486 | 0 | case 'g': |
487 | 0 | append_sstring(p, end, "32;"); |
488 | 0 | break; |
489 | 0 | case 'y': |
490 | 0 | append_sstring(p, end, "33;"); |
491 | 0 | break; |
492 | 0 | case 'b': |
493 | 0 | append_sstring(p, end, "34;"); |
494 | 0 | break; |
495 | 0 | case 'p': |
496 | 0 | append_sstring(p, end, "35;"); |
497 | 0 | break; |
498 | 0 | case 'c': |
499 | 0 | append_sstring(p, end, "36;"); |
500 | 0 | break; |
501 | 0 | case 'w': |
502 | 0 | append_sstring(p, end, "37;"); |
503 | 0 | break; |
504 | 0 | default: |
505 | 0 | LM_ERR("invalid foreground\n"); |
506 | 0 | return pv_get_null(msg, param, res); |
507 | 0 | } |
508 | | |
509 | | /* background */ |
510 | 0 | switch(param->pvn.u.isname.name.s.s[1]) |
511 | 0 | { |
512 | 0 | case 'x': |
513 | 0 | append_sstring(p, end, "49"); |
514 | 0 | break; |
515 | 0 | case 's': |
516 | 0 | append_sstring(p, end, "40"); |
517 | 0 | break; |
518 | 0 | case 'r': |
519 | 0 | append_sstring(p, end, "41"); |
520 | 0 | break; |
521 | 0 | case 'g': |
522 | 0 | append_sstring(p, end, "42"); |
523 | 0 | break; |
524 | 0 | case 'y': |
525 | 0 | append_sstring(p, end, "43"); |
526 | 0 | break; |
527 | 0 | case 'b': |
528 | 0 | append_sstring(p, end, "44"); |
529 | 0 | break; |
530 | 0 | case 'p': |
531 | 0 | append_sstring(p, end, "45"); |
532 | 0 | break; |
533 | 0 | case 'c': |
534 | 0 | append_sstring(p, end, "46"); |
535 | 0 | break; |
536 | 0 | case 'w': |
537 | 0 | append_sstring(p, end, "47"); |
538 | 0 | break; |
539 | 0 | default: |
540 | 0 | LM_ERR("invalid background\n"); |
541 | 0 | return pv_get_null(msg, param, res); |
542 | 0 | } |
543 | | |
544 | | /* end */ |
545 | 0 | append_sstring(p, end, "m"); |
546 | | |
547 | 0 | s.s = color; |
548 | 0 | s.len = p-color; |
549 | 0 | return pv_get_strval(msg, param, res, &s); |
550 | | |
551 | 0 | error: |
552 | 0 | return -1; |
553 | 0 | } |
554 | | |