Merge "res_pjsip/res_pjsip_callerid: NULL check on caller id name string"
[asterisk/asterisk.git] / res / res_pjproject.c
1 /*
2  * Asterisk -- An open source telephony toolkit.
3  *
4  * Copyright (C) 2013, Digium, Inc.
5  *
6  * David M. Lee, II <dlee@digium.com>
7  *
8  * See http://www.asterisk.org for more information about
9  * the Asterisk project. Please do not directly contact
10  * any of the maintainers of this project for assistance;
11  * the project provides a web site, mailing lists and IRC
12  * channels for your use.
13  *
14  * This program is free software, distributed under the terms of
15  * the GNU General Public License Version 2. See the LICENSE file
16  * at the top of the source tree.
17  */
18
19 /*! \file
20  *
21  * \brief Bridge PJPROJECT logging to Asterisk logging.
22  * \author David M. Lee, II <dlee@digium.com>
23  *
24  * PJPROJECT logging doesn't exactly match Asterisk logging, but mapping the two is
25  * not too bad. PJPROJECT log levels are identified by a single int. Limits are
26  * not specified by PJPROJECT, but their implementation used 1 through 6.
27  *
28  * The mapping is as follows:
29  *  - 0: LOG_ERROR
30  *  - 1: LOG_ERROR
31  *  - 2: LOG_WARNING
32  *  - 3 and above: equivalent to ast_debug(level, ...) for res_pjproject.so
33  */
34
35 /*** MODULEINFO
36         <depend>pjproject</depend>
37         <support_level>core</support_level>
38  ***/
39
40 /*** DOCUMENTATION
41         <configInfo name="res_pjproject" language="en_US">
42                 <synopsis>pjproject common configuration</synopsis>
43                 <configFile name="pjproject.conf">
44                         <configObject name="startup">
45                                 <synopsis>Asterisk startup time options for PJPROJECT</synopsis>
46                                 <description>
47                                         <note><para>The id of this object, as well as its type, must be
48                                         'startup' or it won't be found.</para></note>
49                                 </description>
50                                 <configOption name="type">
51                                         <synopsis>Must be of type 'startup'.</synopsis>
52                                 </configOption>
53                                 <configOption name="log_level" default="2">
54                                         <synopsis>Initial maximum pjproject logging level to log.</synopsis>
55                                         <description>
56                                                 <para>Valid values are: 0-6, and default</para>
57                                         <note><para>
58                                                 This option is needed very early in the startup process
59                                                 so it can only be read from config files because the
60                                                 modules for other methods have not been loaded yet.
61                                         </para></note>
62                                         </description>
63                                 </configOption>
64                         </configObject>
65                         <configObject name="log_mappings">
66                                 <synopsis>PJPROJECT to Asterisk Log Level Mapping</synopsis>
67                                 <description><para>Warnings and errors in the pjproject libraries are generally handled
68                                         by Asterisk.  In many cases, Asterisk wouldn't even consider them to
69                                         be warnings or errors so the messages emitted by pjproject directly
70                                         are either superfluous or misleading.  The 'log_mappings'
71                                         object allows mapping the pjproject levels to Asterisk levels, or nothing.
72                                         </para>
73                                         <note><para>The id of this object, as well as its type, must be
74                                         'log_mappings' or it won't be found.</para></note>
75                                 </description>
76                                 <configOption name="type">
77                                         <synopsis>Must be of type 'log_mappings'.</synopsis>
78                                 </configOption>
79                                 <configOption name="asterisk_error" default="0,1">
80                                         <synopsis>A comma separated list of pjproject log levels to map to Asterisk LOG_ERROR.</synopsis>
81                                 </configOption>
82                                 <configOption name="asterisk_warning" default="2">
83                                         <synopsis>A comma separated list of pjproject log levels to map to Asterisk LOG_WARNING.</synopsis>
84                                 </configOption>
85                                 <configOption name="asterisk_notice" default="">
86                                         <synopsis>A comma separated list of pjproject log levels to map to Asterisk LOG_NOTICE.</synopsis>
87                                 </configOption>
88                                 <configOption name="asterisk_debug" default="3,4,5,6">
89                                         <synopsis>A comma separated list of pjproject log levels to map to Asterisk LOG_DEBUG.</synopsis>
90                                 </configOption>
91                                 <configOption name="asterisk_verbose" default="">
92                                         <synopsis>A comma separated list of pjproject log levels to map to Asterisk LOG_VERBOSE.</synopsis>
93                                 </configOption>
94                         </configObject>
95                 </configFile>
96         </configInfo>
97  ***/
98
99 #include "asterisk.h"
100
101 #include <stdarg.h>
102 #include <pjlib.h>
103 #include <pjsip.h>
104 #include <pj/log.h>
105
106 #include "asterisk/options.h"
107 #include "asterisk/logger.h"
108 #include "asterisk/module.h"
109 #include "asterisk/cli.h"
110 #include "asterisk/res_pjproject.h"
111 #include "asterisk/vector.h"
112 #include "asterisk/sorcery.h"
113
114 static struct ast_sorcery *pjproject_sorcery;
115 static pj_log_func *log_cb_orig;
116 static unsigned decor_orig;
117
118 static AST_VECTOR(buildopts, char *) buildopts;
119
120 /*! Protection from other log intercept instances.  There can be only one at a time. */
121 AST_MUTEX_DEFINE_STATIC(pjproject_log_intercept_lock);
122
123 struct pjproject_log_intercept_data {
124         pthread_t thread;
125         int fd;
126 };
127
128 static struct pjproject_log_intercept_data pjproject_log_intercept = {
129         .thread = AST_PTHREADT_NULL,
130         .fd = -1,
131 };
132
133 struct log_mappings {
134         /*! Sorcery object details */
135         SORCERY_OBJECT(details);
136         /*! These are all comma-separated lists of pjproject log levels */
137         AST_DECLARE_STRING_FIELDS(
138                 /*! pjproject log levels mapped to Asterisk ERROR */
139                 AST_STRING_FIELD(asterisk_error);
140                 /*! pjproject log levels mapped to Asterisk WARNING */
141                 AST_STRING_FIELD(asterisk_warning);
142                 /*! pjproject log levels mapped to Asterisk NOTICE */
143                 AST_STRING_FIELD(asterisk_notice);
144                 /*! pjproject log levels mapped to Asterisk VERBOSE */
145                 AST_STRING_FIELD(asterisk_verbose);
146                 /*! pjproject log levels mapped to Asterisk DEBUG */
147                 AST_STRING_FIELD(asterisk_debug);
148         );
149 };
150
151 static struct log_mappings *default_log_mappings;
152
153 static struct log_mappings *get_log_mappings(void)
154 {
155         struct log_mappings *mappings;
156
157         mappings = ast_sorcery_retrieve_by_id(pjproject_sorcery, "log_mappings", "log_mappings");
158         if (!mappings) {
159                 return ao2_bump(default_log_mappings);
160         }
161
162         return mappings;
163 }
164
165 #define __LOG_SUPPRESS -1
166
167 static int get_log_level(int pj_level)
168 {
169         int mapped_level;
170         unsigned char l;
171         struct log_mappings *mappings;
172
173         mappings = get_log_mappings();
174         if (!mappings) {
175                 return __LOG_ERROR;
176         }
177
178         l = '0' + fmin(pj_level, 9);
179
180         if (strchr(mappings->asterisk_error, l)) {
181                 mapped_level = __LOG_ERROR;
182         } else if (strchr(mappings->asterisk_warning, l)) {
183                 mapped_level = __LOG_WARNING;
184         } else if (strchr(mappings->asterisk_notice, l)) {
185                 mapped_level = __LOG_NOTICE;
186         } else if (strchr(mappings->asterisk_verbose, l)) {
187                 mapped_level = __LOG_VERBOSE;
188         } else if (strchr(mappings->asterisk_debug, l)) {
189                 mapped_level = __LOG_DEBUG;
190         } else {
191                 mapped_level = __LOG_SUPPRESS;
192         }
193
194         ao2_ref(mappings, -1);
195         return mapped_level;
196 }
197
198 static void log_forwarder(int level, const char *data, int len)
199 {
200         int ast_level;
201         /* PJPROJECT doesn't provide much in the way of source info */
202         const char * log_source = "pjproject";
203         int log_line = 0;
204         const char *log_func = "<?>";
205
206         if (pjproject_log_intercept.fd != -1
207                 && pjproject_log_intercept.thread == pthread_self()) {
208                 /*
209                  * We are handling a CLI command intercepting PJPROJECT
210                  * log output.
211                  */
212                 ast_cli(pjproject_log_intercept.fd, "%s\n", data);
213                 return;
214         }
215
216         ast_level = get_log_level(level);
217
218         if (ast_level == __LOG_SUPPRESS) {
219                 return;
220         }
221
222         /* PJPROJECT uses indention to indicate function call depth. We'll prepend
223          * log statements with a tab so they'll have a better shot at lining
224          * up */
225         ast_log(ast_level, log_source, log_line, log_func, "\t%s\n", data);
226 }
227
228 static void capture_buildopts_cb(int level, const char *data, int len)
229 {
230         if (strstr(data, "Teluu") || strstr(data, "Dumping")) {
231                 return;
232         }
233
234         AST_VECTOR_ADD_SORTED(&buildopts, ast_strdup(ast_skip_blanks(data)), strcmp);
235 }
236
237 #pragma GCC diagnostic ignored "-Wformat-nonliteral"
238 int ast_pjproject_get_buildopt(char *option, char *format_string, ...)
239 {
240         int res = 0;
241         char *format_temp;
242         int i;
243
244         format_temp = ast_alloca(strlen(option) + strlen(" : ") + strlen(format_string) + 1);
245         sprintf(format_temp, "%s : %s", option, format_string);
246
247         for (i = 0; i < AST_VECTOR_SIZE(&buildopts); i++) {
248                 va_list arg_ptr;
249                 va_start(arg_ptr, format_string);
250                 res = vsscanf(AST_VECTOR_GET(&buildopts, i), format_temp, arg_ptr);
251                 va_end(arg_ptr);
252                 if (res) {
253                         break;
254                 }
255         }
256
257         return res;
258 }
259 #pragma GCC diagnostic warning "-Wformat-nonliteral"
260
261 void ast_pjproject_log_intercept_begin(int fd)
262 {
263         /* Protect from other CLI instances trying to do this at the same time. */
264         ast_mutex_lock(&pjproject_log_intercept_lock);
265
266         pjproject_log_intercept.thread = pthread_self();
267         pjproject_log_intercept.fd = fd;
268 }
269
270 void ast_pjproject_log_intercept_end(void)
271 {
272         pjproject_log_intercept.fd = -1;
273         pjproject_log_intercept.thread = AST_PTHREADT_NULL;
274
275         ast_mutex_unlock(&pjproject_log_intercept_lock);
276 }
277
278 void ast_pjproject_ref(void)
279 {
280         ast_module_ref(ast_module_info->self);
281 }
282
283 void ast_pjproject_unref(void)
284 {
285         ast_module_unref(ast_module_info->self);
286 }
287
288 static char *handle_pjproject_show_buildopts(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
289 {
290         int i;
291
292         switch (cmd) {
293         case CLI_INIT:
294                 e->command = "pjproject show buildopts";
295                 e->usage =
296                         "Usage: pjproject show buildopts\n"
297                         "       Show the compile time config of the pjproject that Asterisk is\n"
298                         "       running against.\n";
299                 return NULL;
300         case CLI_GENERATE:
301                 return NULL;
302         }
303
304         ast_cli(a->fd, "PJPROJECT compile time config currently running against:\n");
305
306         for (i = 0; i < AST_VECTOR_SIZE(&buildopts); i++) {
307                 ast_cli(a->fd, "%s\n", AST_VECTOR_GET(&buildopts, i));
308         }
309
310         return CLI_SUCCESS;
311 }
312
313 static void mapping_destroy(void *object)
314 {
315         struct log_mappings *mappings = object;
316
317         ast_string_field_free_memory(mappings);
318 }
319
320 static void *mapping_alloc(const char *name)
321 {
322         struct log_mappings *mappings = ast_sorcery_generic_alloc(sizeof(*mappings), mapping_destroy);
323         if (!mappings) {
324                 return NULL;
325         }
326         ast_string_field_init(mappings, 128);
327
328         return mappings;
329 }
330
331 static char *handle_pjproject_show_log_mappings(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
332 {
333         struct ast_variable *objset;
334         struct ast_variable *i;
335         struct log_mappings *mappings;
336
337         switch (cmd) {
338         case CLI_INIT:
339                 e->command = "pjproject show log mappings";
340                 e->usage =
341                         "Usage: pjproject show log mappings\n"
342                         "       Show pjproject to Asterisk log mappings\n";
343                 return NULL;
344         case CLI_GENERATE:
345                 return NULL;
346         }
347
348         ast_cli(a->fd, "PJPROJECT to Asterisk log mappings:\n");
349         ast_cli(a->fd, "Asterisk Level   : PJPROJECT log levels\n");
350
351         mappings = get_log_mappings();
352         if (!mappings) {
353                 ast_log(LOG_ERROR, "Unable to retrieve pjproject log_mappings\n");
354                 return CLI_SUCCESS;
355         }
356
357         objset = ast_sorcery_objectset_create(pjproject_sorcery, mappings);
358         if (!objset) {
359                 ao2_ref(mappings, -1);
360                 return CLI_SUCCESS;
361         }
362
363         for (i = objset; i; i = i->next) {
364                 ast_cli(a->fd, "%-16s : %s\n", i->name, i->value);
365         }
366         ast_variables_destroy(objset);
367
368         ao2_ref(mappings, -1);
369         return CLI_SUCCESS;
370 }
371
372 struct max_pjproject_log_level_check {
373         /*!
374          * Compile time sanity check to determine if
375          * MAX_PJ_LOG_MAX_LEVEL matches CLI syntax.
376          */
377         char check[1 / (6 == MAX_PJ_LOG_MAX_LEVEL)];
378 };
379
380 static char *handle_pjproject_set_log_level(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
381 {
382         int level_new;
383         int level_old;
384
385         switch (cmd) {
386         case CLI_INIT:
387                 e->command = "pjproject set log level {default|0|1|2|3|4|5|6}";
388                 e->usage =
389                         "Usage: pjproject set log level {default|<level>}\n"
390                         "\n"
391                         "       Set the maximum active pjproject logging level.\n"
392                         "       See pjproject.conf.sample for additional information\n"
393                         "       about the various levels pjproject uses.\n";
394                 return NULL;
395         case CLI_GENERATE:
396                 return NULL;
397         }
398
399         if (a->argc != 5) {
400                 return CLI_SHOWUSAGE;
401         }
402
403         if (!strcasecmp(a->argv[4], "default")) {
404                 level_new = DEFAULT_PJ_LOG_MAX_LEVEL;
405         } else {
406                 if (sscanf(a->argv[4], "%30d", &level_new) != 1
407                         || level_new < 0 || MAX_PJ_LOG_MAX_LEVEL < level_new) {
408                         return CLI_SHOWUSAGE;
409                 }
410         }
411
412         /* Update pjproject logging level */
413         if (ast_pjproject_max_log_level < level_new) {
414                 level_new = ast_pjproject_max_log_level;
415                 ast_cli(a->fd,
416                         "Asterisk built or linked with pjproject PJ_LOG_MAX_LEVEL=%d.\n"
417                         "Lowering request to the max supported level.\n",
418                         ast_pjproject_max_log_level);
419         }
420         level_old = ast_option_pjproject_log_level;
421         if (level_old == level_new) {
422                 ast_cli(a->fd, "pjproject log level is still %d.\n", level_old);
423         } else {
424                 ast_cli(a->fd, "pjproject log level was %d and is now %d.\n",
425                         level_old, level_new);
426                 ast_option_pjproject_log_level = level_new;
427                 pj_log_set_level(level_new);
428         }
429
430         return CLI_SUCCESS;
431 }
432
433 static char *handle_pjproject_show_log_level(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
434 {
435         switch (cmd) {
436         case CLI_INIT:
437                 e->command = "pjproject show log level";
438                 e->usage =
439                         "Usage: pjproject show log level\n"
440                         "\n"
441                         "       Show the current maximum active pjproject logging level.\n"
442                         "       See pjproject.conf.sample for additional information\n"
443                         "       about the various levels pjproject uses.\n";
444                 return NULL;
445         case CLI_GENERATE:
446                 return NULL;
447         }
448
449         if (a->argc != 4) {
450                 return CLI_SHOWUSAGE;
451         }
452
453         ast_cli(a->fd, "pjproject log level is %d.%s\n",
454                 ast_option_pjproject_log_level,
455                 ast_option_pjproject_log_level == DEFAULT_PJ_LOG_MAX_LEVEL ? " (default)" : "");
456
457         return CLI_SUCCESS;
458 }
459
460 static struct ast_cli_entry pjproject_cli[] = {
461         AST_CLI_DEFINE(handle_pjproject_set_log_level, "Set the maximum active pjproject logging level"),
462         AST_CLI_DEFINE(handle_pjproject_show_buildopts, "Show the compiled config of the pjproject in use"),
463         AST_CLI_DEFINE(handle_pjproject_show_log_mappings, "Show pjproject to Asterisk log mappings"),
464         AST_CLI_DEFINE(handle_pjproject_show_log_level, "Show the maximum active pjproject logging level"),
465 };
466
467 static int load_module(void)
468 {
469         ast_debug(3, "Starting PJPROJECT logging to Asterisk logger\n");
470
471         if (!(pjproject_sorcery = ast_sorcery_open())) {
472                 ast_log(LOG_ERROR, "Failed to open SIP sorcery failed to open\n");
473                 return AST_MODULE_LOAD_DECLINE;
474         }
475
476         ast_sorcery_apply_default(pjproject_sorcery, "log_mappings", "config", "pjproject.conf,criteria=type=log_mappings");
477         if (ast_sorcery_object_register(pjproject_sorcery, "log_mappings", mapping_alloc, NULL, NULL)) {
478                 ast_log(LOG_WARNING, "Failed to register pjproject log_mappings object with sorcery\n");
479                 ast_sorcery_unref(pjproject_sorcery);
480                 pjproject_sorcery = NULL;
481                 return AST_MODULE_LOAD_DECLINE;
482         }
483
484         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "type", "", OPT_NOOP_T, 0, 0);
485         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_debug", "", OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_debug));
486         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_error", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_error));
487         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_warning", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_warning));
488         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_notice", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_notice));
489         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_verbose", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_verbose));
490
491         default_log_mappings = ast_sorcery_alloc(pjproject_sorcery, "log_mappings", "log_mappings");
492         if (!default_log_mappings) {
493                 ast_log(LOG_ERROR, "Unable to allocate memory for pjproject log_mappings\n");
494                 return AST_MODULE_LOAD_DECLINE;
495         }
496         ast_string_field_set(default_log_mappings, asterisk_error, "0,1");
497         ast_string_field_set(default_log_mappings, asterisk_warning, "2");
498         ast_string_field_set(default_log_mappings, asterisk_debug, "3,4,5,6");
499
500         ast_sorcery_load(pjproject_sorcery);
501
502         AST_PJPROJECT_INIT_LOG_LEVEL();
503         pj_init();
504
505         decor_orig = pj_log_get_decor();
506         log_cb_orig = pj_log_get_log_func();
507
508         if (AST_VECTOR_INIT(&buildopts, 64)) {
509                 return AST_MODULE_LOAD_DECLINE;
510         }
511
512         /*
513          * On startup, we want to capture the dump once and store it.
514          */
515         pj_log_set_log_func(capture_buildopts_cb);
516         pj_log_set_decor(0);
517         pj_log_set_level(MAX_PJ_LOG_MAX_LEVEL);/* Set level to guarantee the dump output. */
518         pj_dump_config();
519         pj_log_set_decor(PJ_LOG_HAS_SENDER | PJ_LOG_HAS_INDENT);
520         pj_log_set_log_func(log_forwarder);
521         if (ast_pjproject_max_log_level < ast_option_pjproject_log_level) {
522                 ast_log(LOG_WARNING,
523                         "Asterisk built or linked with pjproject PJ_LOG_MAX_LEVEL=%d which is too low for startup level: %d.\n",
524                         ast_pjproject_max_log_level, ast_option_pjproject_log_level);
525                 ast_option_pjproject_log_level = ast_pjproject_max_log_level;
526         }
527         pj_log_set_level(ast_option_pjproject_log_level);
528         if (!AST_VECTOR_SIZE(&buildopts)) {
529                 ast_log(LOG_NOTICE,
530                         "Asterisk built or linked with pjproject PJ_LOG_MAX_LEVEL=%d which is too low to get buildopts.\n",
531                         ast_pjproject_max_log_level);
532         }
533
534         ast_cli_register_multiple(pjproject_cli, ARRAY_LEN(pjproject_cli));
535
536         return AST_MODULE_LOAD_SUCCESS;
537 }
538
539 #define NOT_EQUALS(a, b) (a != b)
540
541 static int unload_module(void)
542 {
543         ast_cli_unregister_multiple(pjproject_cli, ARRAY_LEN(pjproject_cli));
544         pj_log_set_log_func(log_cb_orig);
545         pj_log_set_decor(decor_orig);
546
547         AST_VECTOR_REMOVE_CMP_UNORDERED(&buildopts, NULL, NOT_EQUALS, ast_free);
548         AST_VECTOR_FREE(&buildopts);
549
550         ast_debug(3, "Stopped PJPROJECT logging to Asterisk logger\n");
551
552         pj_shutdown();
553
554         ao2_cleanup(default_log_mappings);
555         default_log_mappings = NULL;
556
557         ast_sorcery_unref(pjproject_sorcery);
558
559         return 0;
560 }
561
562 static int reload_module(void)
563 {
564         if (pjproject_sorcery) {
565                 ast_sorcery_reload(pjproject_sorcery);
566         }
567
568         return AST_MODULE_LOAD_SUCCESS;
569 }
570
571 AST_MODULE_INFO(ASTERISK_GPL_KEY, AST_MODFLAG_GLOBAL_SYMBOLS | AST_MODFLAG_LOAD_ORDER, "PJPROJECT Log and Utility Support",
572         .support_level = AST_MODULE_SUPPORT_CORE,
573         .load = load_module,
574         .unload = unload_module,
575         .reload = reload_module,
576         .load_pri = AST_MODPRI_CHANNEL_DEPEND - 6,
577 );