From f175c7118879b882343da9b6f15075161923fcca Mon Sep 17 00:00:00 2001 From: Nathan Neulinger Date: Tue, 11 Nov 2014 13:25:47 -0600 Subject: [PATCH] FS-6805 add support for logging full timestamps with dialplan, defaults to old behavior unless requested --- conf/curl/autoload_configs/switch.conf.xml | 2 + .../autoload_configs/switch.conf.xml | 2 + conf/rayo/autoload_configs/switch.conf.xml | 3 + conf/sbc/autoload_configs/switch.conf.xml | 2 + conf/vanilla/autoload_configs/switch.conf.xml | 3 + src/include/switch_types.h | 3 +- .../mod_dialplan_xml/mod_dialplan_xml.c | 113 +++++++++++++++--- src/switch_core.c | 6 + src/switch_core_session.c | 7 +- 9 files changed, 124 insertions(+), 17 deletions(-) diff --git a/conf/curl/autoload_configs/switch.conf.xml b/conf/curl/autoload_configs/switch.conf.xml index 09d1c07393..bb9af4f3fa 100644 --- a/conf/curl/autoload_configs/switch.conf.xml +++ b/conf/curl/autoload_configs/switch.conf.xml @@ -18,6 +18,8 @@ + + diff --git a/conf/insideout/autoload_configs/switch.conf.xml b/conf/insideout/autoload_configs/switch.conf.xml index 09d1c07393..bb9af4f3fa 100644 --- a/conf/insideout/autoload_configs/switch.conf.xml +++ b/conf/insideout/autoload_configs/switch.conf.xml @@ -18,6 +18,8 @@ + + diff --git a/conf/rayo/autoload_configs/switch.conf.xml b/conf/rayo/autoload_configs/switch.conf.xml index ddf41f8996..e618069ab2 100644 --- a/conf/rayo/autoload_configs/switch.conf.xml +++ b/conf/rayo/autoload_configs/switch.conf.xml @@ -24,6 +24,9 @@ + + + diff --git a/conf/sbc/autoload_configs/switch.conf.xml b/conf/sbc/autoload_configs/switch.conf.xml index 09d1c07393..bb9af4f3fa 100644 --- a/conf/sbc/autoload_configs/switch.conf.xml +++ b/conf/sbc/autoload_configs/switch.conf.xml @@ -18,6 +18,8 @@ + + diff --git a/conf/vanilla/autoload_configs/switch.conf.xml b/conf/vanilla/autoload_configs/switch.conf.xml index d508ad1844..102a2a7f1e 100644 --- a/conf/vanilla/autoload_configs/switch.conf.xml +++ b/conf/vanilla/autoload_configs/switch.conf.xml @@ -24,6 +24,9 @@ + + + diff --git a/src/include/switch_types.h b/src/include/switch_types.h index 6b9f303f47..69602de419 100644 --- a/src/include/switch_types.h +++ b/src/include/switch_types.h @@ -361,7 +361,8 @@ typedef enum { SCF_CORE_NON_SQLITE_DB_REQ = (1 << 20), SCF_DEBUG_SQL = (1 << 21), SCF_API_EXPANSION = (1 << 22), - SCF_SESSION_THREAD_POOL = (1 << 23) + SCF_SESSION_THREAD_POOL = (1 << 23), + SCF_DIALPLAN_TIMESTAMPS = (1 << 24) } switch_core_flag_enum_t; typedef uint32_t switch_core_flag_t; diff --git a/src/mod/dialplans/mod_dialplan_xml/mod_dialplan_xml.c b/src/mod/dialplans/mod_dialplan_xml/mod_dialplan_xml.c index b5ff5e63a6..71908b36f0 100644 --- a/src/mod/dialplans/mod_dialplan_xml/mod_dialplan_xml.c +++ b/src/mod/dialplans/mod_dialplan_xml/mod_dialplan_xml.c @@ -148,10 +148,15 @@ static int parse_exten(switch_core_session_t *session, switch_caller_profile_t * req_nest = switch_true(req_nesta); } - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: Processing recursive conditions level:%d [%s] require-nested=%s\n", space, recur, exten_name, req_nest ? "TRUE" : "FALSE"); - + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: Processing recursive conditions level:%d [%s] require-nested=%s\n", space, + recur, exten_name, req_nest ? "TRUE" : "FALSE"); + } } else { if ((tmp = switch_xml_attr(xexten, "name"))) { exten_name = tmp; @@ -204,15 +209,27 @@ static int parse_exten(switch_core_session_t *session, switch_caller_profile_t * } if (time_match == 1) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Date/Time Match (PASS) [%s] break=%s\n", space, switch_channel_get_name(channel), exten_name, do_break_a ? do_break_a : "on-false"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Date/Time Match (PASS) [%s] break=%s\n", space, + switch_channel_get_name(channel), exten_name, do_break_a ? do_break_a : "on-false"); + } anti_action = SWITCH_FALSE; proceed = 1; } else if (time_match == 0) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Date/TimeMatch (FAIL) [%s] break=%s\n", space, switch_channel_get_name(channel), exten_name, do_break_a ? do_break_a : "on-false"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Date/TimeMatch (FAIL) [%s] break=%s\n", space, + switch_channel_get_name(channel), exten_name, do_break_a ? do_break_a : "on-false"); + } } @@ -230,14 +247,26 @@ static int parse_exten(switch_core_session_t *session, switch_caller_profile_t * time_match = switch_xml_std_datetime_check(xregex, tzoff ? &offset : NULL, tzname_); if (time_match == 1) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Date/Time Match (PASS) [%s]\n", space, switch_channel_get_name(channel), exten_name); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Date/Time Match (PASS) [%s]\n", space, + switch_channel_get_name(channel), exten_name); + } anti_action = SWITCH_FALSE; } else if (time_match == 0) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Date/TimeMatch (FAIL) [%s]\n", space, switch_channel_get_name(channel), exten_name); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Date/TimeMatch (FAIL) [%s]\n", space, + switch_channel_get_name(channel), exten_name); + } } @@ -273,22 +302,40 @@ static int parse_exten(switch_core_session_t *session, switch_caller_profile_t * } if ((proceed = switch_regex_perform(field_data, expression, &re, ovector, sizeof(ovector) / sizeof(ovector[0])))) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Regex (PASS) [%s] %s(%s) =~ /%s/ match=%s\n", space, switch_channel_get_name(channel), exten_name, field, field_data, expression, all ? "all" : "any"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Regex (PASS) [%s] %s(%s) =~ /%s/ match=%s\n", space, + switch_channel_get_name(channel), exten_name, field, field_data, expression, all ? "all" : "any"); + } pass++; if (!all && !xor) break; } else { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Regex (FAIL) [%s] %s(%s) =~ /%s/ match=%s\n", space, switch_channel_get_name(channel), exten_name, field, field_data, expression, all ? "all" : "any"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Regex (FAIL) [%s] %s(%s) =~ /%s/ match=%s\n", space, + switch_channel_get_name(channel), exten_name, field, field_data, expression, all ? "all" : "any"); + } fail++; if (all && !xor) break; } } else if (time_match == -1) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Absolute Condition [%s] match=%s\n", space, switch_channel_get_name(channel), exten_name, all ? "all" : "any"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Absolute Condition [%s] match=%s\n", space, + switch_channel_get_name(channel), exten_name, all ? "all" : "any"); + } pass++; proceed = 1; if (!all && !xor) break; @@ -367,19 +414,37 @@ static int parse_exten(switch_core_session_t *session, switch_caller_profile_t * } if ((proceed = switch_regex_perform(field_data, expression, &re, ovector, sizeof(ovector) / sizeof(ovector[0])))) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Regex (PASS) [%s] %s(%s) =~ /%s/ break=%s\n", space, switch_channel_get_name(channel), exten_name, field, field_data, expression, do_break_a ? do_break_a : "on-false"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Regex (PASS) [%s] %s(%s) =~ /%s/ break=%s\n", space, + switch_channel_get_name(channel), exten_name, field, field_data, expression, do_break_a ? do_break_a : "on-false"); + } anti_action = SWITCH_FALSE; } else { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Regex (FAIL) [%s] %s(%s) =~ /%s/ break=%s\n", space, switch_channel_get_name(channel), exten_name, field, field_data, expression, do_break_a ? do_break_a : "on-false"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Regex (FAIL) [%s] %s(%s) =~ /%s/ break=%s\n", space, + switch_channel_get_name(channel), exten_name, field, field_data, expression, do_break_a ? do_break_a : "on-false"); + } } } else if (time_match == -1) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Absolute Condition [%s]\n", space, switch_channel_get_name(channel), exten_name); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Absolute Condition [%s]\n", space, + switch_channel_get_name(channel), exten_name); + } anti_action = SWITCH_FALSE; proceed = 1; } @@ -427,9 +492,15 @@ static int parse_exten(switch_core_session_t *session, switch_caller_profile_t * } for (;loop_count > 0; loop_count--) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s ANTI-Action %s(%s) %s\n", space, switch_channel_get_name(channel), application, data, xinline ? "INLINE" : ""); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s ANTI-Action %s(%s) %s\n", space, + switch_channel_get_name(channel), application, data, xinline ? "INLINE" : ""); + } if (xinline) { exec_app(session, application, data); @@ -488,9 +559,15 @@ static int parse_exten(switch_core_session_t *session, switch_caller_profile_t * loop_count = atoi(loop); } for (;loop_count > 0; loop_count--) { - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%sDialplan: %s Action %s(%s) %s\n", space, switch_channel_get_name(channel), application, app_data, xinline ? "INLINE" : ""); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "%sDialplan: %s Action %s(%s) %s\n", space, + switch_channel_get_name(channel), application, app_data, xinline ? "INLINE" : ""); + } if (xinline) { exec_app(session, application, app_data); @@ -607,9 +684,15 @@ SWITCH_STANDARD_DIALPLAN(dialplan_hunt) exten_name = "UNKNOWN"; } - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Dialplan: %s parsing [%s->%s] continue=%s\n", switch_channel_get_name(channel), caller_profile->context, exten_name, cont ? cont : "false"); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, + "Dialplan: %s parsing [%s->%s] continue=%s\n", + switch_channel_get_name(channel), caller_profile->context, exten_name, cont ? cont : "false"); + } proceed = parse_exten(session, caller_profile, xexten, &extension, exten_name, 0); diff --git a/src/switch_core.c b/src/switch_core.c index cbf3175679..bccaadc2b2 100644 --- a/src/switch_core.c +++ b/src/switch_core.c @@ -1980,6 +1980,12 @@ static void switch_load_core_config(const char *file) runtime.core_db_inner_pre_trans_execute = switch_core_strdup(runtime.memory_pool, val); } else if (!strcasecmp(var, "core-db-inner-post-trans-execute") && !zstr(val)) { runtime.core_db_inner_post_trans_execute = switch_core_strdup(runtime.memory_pool, val); + } else if (!strcasecmp(var, "dialplan-timestamps")) { + if (switch_true(val)) { + switch_set_flag((&runtime), SCF_DIALPLAN_TIMESTAMPS); + } else { + switch_clear_flag((&runtime), SCF_DIALPLAN_TIMESTAMPS); + } } else if (!strcasecmp(var, "mailer-app") && !zstr(val)) { runtime.mailer_app = switch_core_strdup(runtime.memory_pool, val); } else if (!strcasecmp(var, "mailer-app-args") && val) { diff --git a/src/switch_core_session.c b/src/switch_core_session.c index c5f1eaa718..a3728234e1 100644 --- a/src/switch_core_session.c +++ b/src/switch_core_session.c @@ -2811,8 +2811,13 @@ SWITCH_DECLARE(switch_status_t) switch_core_session_exec(switch_core_session_t * } - switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, "EXECUTE %s %s(%s)\n", + if ( switch_core_test_flag(SCF_DIALPLAN_TIMESTAMPS) ) { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "EXECUTE %s %s(%s)\n", switch_channel_get_name(session->channel), app, switch_str_nil(expanded)); + } else { + switch_log_printf(SWITCH_CHANNEL_SESSION_LOG_CLEAN(session), SWITCH_LOG_DEBUG, "EXECUTE %s %s(%s)\n", + switch_channel_get_name(session->channel), app, switch_str_nil(expanded)); + } if ((var = switch_channel_get_variable(session->channel, "verbose_presence")) && switch_true(var)) { char *myarg = NULL;