res_pjsip: Use reasonable buffer lengths for endpoint identification
[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         char *dup;
231
232         if (strstr(data, "Teluu") || strstr(data, "Dumping")) {
233                 return;
234         }
235
236         dup = ast_strdup(ast_skip_blanks(data));
237         if (dup && AST_VECTOR_ADD_SORTED(&buildopts, dup, strcmp)) {
238                 ast_free(dup);
239         }
240 }
241
242 #pragma GCC diagnostic ignored "-Wformat-nonliteral"
243 int ast_pjproject_get_buildopt(char *option, char *format_string, ...)
244 {
245         int res = 0;
246         char *format_temp;
247         int i;
248
249         format_temp = ast_alloca(strlen(option) + strlen(" : ") + strlen(format_string) + 1);
250         sprintf(format_temp, "%s : %s", option, format_string);
251
252         for (i = 0; i < AST_VECTOR_SIZE(&buildopts); i++) {
253                 va_list arg_ptr;
254                 va_start(arg_ptr, format_string);
255                 res = vsscanf(AST_VECTOR_GET(&buildopts, i), format_temp, arg_ptr);
256                 va_end(arg_ptr);
257                 if (res) {
258                         break;
259                 }
260         }
261
262         return res;
263 }
264 #pragma GCC diagnostic warning "-Wformat-nonliteral"
265
266 void ast_pjproject_log_intercept_begin(int fd)
267 {
268         /* Protect from other CLI instances trying to do this at the same time. */
269         ast_mutex_lock(&pjproject_log_intercept_lock);
270
271         pjproject_log_intercept.thread = pthread_self();
272         pjproject_log_intercept.fd = fd;
273 }
274
275 void ast_pjproject_log_intercept_end(void)
276 {
277         pjproject_log_intercept.fd = -1;
278         pjproject_log_intercept.thread = AST_PTHREADT_NULL;
279
280         ast_mutex_unlock(&pjproject_log_intercept_lock);
281 }
282
283 void ast_pjproject_ref(void)
284 {
285         ast_module_ref(ast_module_info->self);
286 }
287
288 void ast_pjproject_unref(void)
289 {
290         ast_module_unref(ast_module_info->self);
291 }
292
293 static char *handle_pjproject_show_buildopts(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
294 {
295         int i;
296
297         switch (cmd) {
298         case CLI_INIT:
299                 e->command = "pjproject show buildopts";
300                 e->usage =
301                         "Usage: pjproject show buildopts\n"
302                         "       Show the compile time config of the pjproject that Asterisk is\n"
303                         "       running against.\n";
304                 return NULL;
305         case CLI_GENERATE:
306                 return NULL;
307         }
308
309         ast_cli(a->fd, "PJPROJECT compile time config currently running against:\n");
310
311         for (i = 0; i < AST_VECTOR_SIZE(&buildopts); i++) {
312                 ast_cli(a->fd, "%s\n", AST_VECTOR_GET(&buildopts, i));
313         }
314
315         return CLI_SUCCESS;
316 }
317
318 static void mapping_destroy(void *object)
319 {
320         struct log_mappings *mappings = object;
321
322         ast_string_field_free_memory(mappings);
323 }
324
325 static void *mapping_alloc(const char *name)
326 {
327         struct log_mappings *mappings = ast_sorcery_generic_alloc(sizeof(*mappings), mapping_destroy);
328         if (!mappings) {
329                 return NULL;
330         }
331         ast_string_field_init(mappings, 128);
332
333         return mappings;
334 }
335
336 static char *handle_pjproject_show_log_mappings(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
337 {
338         struct ast_variable *objset;
339         struct ast_variable *i;
340         struct log_mappings *mappings;
341
342         switch (cmd) {
343         case CLI_INIT:
344                 e->command = "pjproject show log mappings";
345                 e->usage =
346                         "Usage: pjproject show log mappings\n"
347                         "       Show pjproject to Asterisk log mappings\n";
348                 return NULL;
349         case CLI_GENERATE:
350                 return NULL;
351         }
352
353         ast_cli(a->fd, "PJPROJECT to Asterisk log mappings:\n");
354         ast_cli(a->fd, "Asterisk Level   : PJPROJECT log levels\n");
355
356         mappings = get_log_mappings();
357         if (!mappings) {
358                 ast_log(LOG_ERROR, "Unable to retrieve pjproject log_mappings\n");
359                 return CLI_SUCCESS;
360         }
361
362         objset = ast_sorcery_objectset_create(pjproject_sorcery, mappings);
363         if (!objset) {
364                 ao2_ref(mappings, -1);
365                 return CLI_SUCCESS;
366         }
367
368         for (i = objset; i; i = i->next) {
369                 ast_cli(a->fd, "%-16s : %s\n", i->name, i->value);
370         }
371         ast_variables_destroy(objset);
372
373         ao2_ref(mappings, -1);
374         return CLI_SUCCESS;
375 }
376
377 struct max_pjproject_log_level_check {
378         /*!
379          * Compile time sanity check to determine if
380          * MAX_PJ_LOG_MAX_LEVEL matches CLI syntax.
381          */
382         char check[1 / (6 == MAX_PJ_LOG_MAX_LEVEL)];
383 };
384
385 static char *handle_pjproject_set_log_level(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
386 {
387         int level_new;
388         int level_old;
389
390         switch (cmd) {
391         case CLI_INIT:
392                 e->command = "pjproject set log level {default|0|1|2|3|4|5|6}";
393                 e->usage =
394                         "Usage: pjproject set log level {default|<level>}\n"
395                         "\n"
396                         "       Set the maximum active pjproject logging level.\n"
397                         "       See pjproject.conf.sample for additional information\n"
398                         "       about the various levels pjproject uses.\n";
399                 return NULL;
400         case CLI_GENERATE:
401                 return NULL;
402         }
403
404         if (a->argc != 5) {
405                 return CLI_SHOWUSAGE;
406         }
407
408         if (!strcasecmp(a->argv[4], "default")) {
409                 level_new = DEFAULT_PJ_LOG_MAX_LEVEL;
410         } else {
411                 if (sscanf(a->argv[4], "%30d", &level_new) != 1
412                         || level_new < 0 || MAX_PJ_LOG_MAX_LEVEL < level_new) {
413                         return CLI_SHOWUSAGE;
414                 }
415         }
416
417         /* Update pjproject logging level */
418         if (ast_pjproject_max_log_level < level_new) {
419                 level_new = ast_pjproject_max_log_level;
420                 ast_cli(a->fd,
421                         "Asterisk built or linked with pjproject PJ_LOG_MAX_LEVEL=%d.\n"
422                         "Lowering request to the max supported level.\n",
423                         ast_pjproject_max_log_level);
424         }
425         level_old = ast_option_pjproject_log_level;
426         if (level_old == level_new) {
427                 ast_cli(a->fd, "pjproject log level is still %d.\n", level_old);
428         } else {
429                 ast_cli(a->fd, "pjproject log level was %d and is now %d.\n",
430                         level_old, level_new);
431                 ast_option_pjproject_log_level = level_new;
432                 pj_log_set_level(level_new);
433         }
434
435         return CLI_SUCCESS;
436 }
437
438 static char *handle_pjproject_show_log_level(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
439 {
440         switch (cmd) {
441         case CLI_INIT:
442                 e->command = "pjproject show log level";
443                 e->usage =
444                         "Usage: pjproject show log level\n"
445                         "\n"
446                         "       Show the current maximum active pjproject logging level.\n"
447                         "       See pjproject.conf.sample for additional information\n"
448                         "       about the various levels pjproject uses.\n";
449                 return NULL;
450         case CLI_GENERATE:
451                 return NULL;
452         }
453
454         if (a->argc != 4) {
455                 return CLI_SHOWUSAGE;
456         }
457
458         ast_cli(a->fd, "pjproject log level is %d.%s\n",
459                 ast_option_pjproject_log_level,
460                 ast_option_pjproject_log_level == DEFAULT_PJ_LOG_MAX_LEVEL ? " (default)" : "");
461
462         return CLI_SUCCESS;
463 }
464
465 static struct ast_cli_entry pjproject_cli[] = {
466         AST_CLI_DEFINE(handle_pjproject_set_log_level, "Set the maximum active pjproject logging level"),
467         AST_CLI_DEFINE(handle_pjproject_show_buildopts, "Show the compiled config of the pjproject in use"),
468         AST_CLI_DEFINE(handle_pjproject_show_log_mappings, "Show pjproject to Asterisk log mappings"),
469         AST_CLI_DEFINE(handle_pjproject_show_log_level, "Show the maximum active pjproject logging level"),
470 };
471
472 static int load_module(void)
473 {
474         ast_debug(3, "Starting PJPROJECT logging to Asterisk logger\n");
475
476         if (!(pjproject_sorcery = ast_sorcery_open())) {
477                 ast_log(LOG_ERROR, "Failed to open SIP sorcery failed to open\n");
478                 return AST_MODULE_LOAD_DECLINE;
479         }
480
481         ast_sorcery_apply_default(pjproject_sorcery, "log_mappings", "config", "pjproject.conf,criteria=type=log_mappings");
482         if (ast_sorcery_object_register(pjproject_sorcery, "log_mappings", mapping_alloc, NULL, NULL)) {
483                 ast_log(LOG_WARNING, "Failed to register pjproject log_mappings object with sorcery\n");
484                 ast_sorcery_unref(pjproject_sorcery);
485                 pjproject_sorcery = NULL;
486                 return AST_MODULE_LOAD_DECLINE;
487         }
488
489         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "type", "", OPT_NOOP_T, 0, 0);
490         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_debug", "", OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_debug));
491         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_error", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_error));
492         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_warning", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_warning));
493         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_notice", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_notice));
494         ast_sorcery_object_field_register(pjproject_sorcery, "log_mappings", "asterisk_verbose", "",  OPT_STRINGFIELD_T, 0, STRFLDSET(struct log_mappings, asterisk_verbose));
495
496         default_log_mappings = ast_sorcery_alloc(pjproject_sorcery, "log_mappings", "log_mappings");
497         if (!default_log_mappings) {
498                 ast_log(LOG_ERROR, "Unable to allocate memory for pjproject log_mappings\n");
499                 return AST_MODULE_LOAD_DECLINE;
500         }
501         ast_string_field_set(default_log_mappings, asterisk_error, "0,1");
502         ast_string_field_set(default_log_mappings, asterisk_warning, "2");
503         ast_string_field_set(default_log_mappings, asterisk_debug, "3,4,5,6");
504
505         ast_sorcery_load(pjproject_sorcery);
506
507         AST_PJPROJECT_INIT_LOG_LEVEL();
508         pj_init();
509
510         decor_orig = pj_log_get_decor();
511         log_cb_orig = pj_log_get_log_func();
512
513         if (AST_VECTOR_INIT(&buildopts, 64)) {
514                 return AST_MODULE_LOAD_DECLINE;
515         }
516
517         /*
518          * On startup, we want to capture the dump once and store it.
519          */
520         pj_log_set_log_func(capture_buildopts_cb);
521         pj_log_set_decor(0);
522         pj_log_set_level(MAX_PJ_LOG_MAX_LEVEL);/* Set level to guarantee the dump output. */
523         pj_dump_config();
524         pj_log_set_decor(PJ_LOG_HAS_SENDER | PJ_LOG_HAS_INDENT);
525         pj_log_set_log_func(log_forwarder);
526         if (ast_pjproject_max_log_level < ast_option_pjproject_log_level) {
527                 ast_log(LOG_WARNING,
528                         "Asterisk built or linked with pjproject PJ_LOG_MAX_LEVEL=%d which is too low for startup level: %d.\n",
529                         ast_pjproject_max_log_level, ast_option_pjproject_log_level);
530                 ast_option_pjproject_log_level = ast_pjproject_max_log_level;
531         }
532         pj_log_set_level(ast_option_pjproject_log_level);
533         if (!AST_VECTOR_SIZE(&buildopts)) {
534                 ast_log(LOG_NOTICE,
535                         "Asterisk built or linked with pjproject PJ_LOG_MAX_LEVEL=%d which is too low to get buildopts.\n",
536                         ast_pjproject_max_log_level);
537         }
538
539         ast_cli_register_multiple(pjproject_cli, ARRAY_LEN(pjproject_cli));
540
541         return AST_MODULE_LOAD_SUCCESS;
542 }
543
544 #define NOT_EQUALS(a, b) (a != b)
545
546 static int unload_module(void)
547 {
548         ast_cli_unregister_multiple(pjproject_cli, ARRAY_LEN(pjproject_cli));
549         pj_log_set_log_func(log_cb_orig);
550         pj_log_set_decor(decor_orig);
551
552         AST_VECTOR_CALLBACK_VOID(&buildopts, ast_free);
553         AST_VECTOR_FREE(&buildopts);
554
555         ast_debug(3, "Stopped PJPROJECT logging to Asterisk logger\n");
556
557         pj_shutdown();
558
559         ao2_cleanup(default_log_mappings);
560         default_log_mappings = NULL;
561
562         ast_sorcery_unref(pjproject_sorcery);
563
564         return 0;
565 }
566
567 static int reload_module(void)
568 {
569         if (pjproject_sorcery) {
570                 ast_sorcery_reload(pjproject_sorcery);
571         }
572
573         return AST_MODULE_LOAD_SUCCESS;
574 }
575
576 AST_MODULE_INFO(ASTERISK_GPL_KEY, AST_MODFLAG_GLOBAL_SYMBOLS | AST_MODFLAG_LOAD_ORDER, "PJPROJECT Log and Utility Support",
577         .support_level = AST_MODULE_SUPPORT_CORE,
578         .load = load_module,
579         .unload = unload_module,
580         .reload = reload_module,
581         .load_pri = AST_MODPRI_CHANNEL_DEPEND - 6,
582 );