Logger/CLI/etc.: Fix some aesthetic issues; reduce chatty verbose messages
authorMatthew Jordan <mjordan@digium.com>
Wed, 28 May 2014 22:54:12 +0000 (22:54 +0000)
committerMatthew Jordan <mjordan@digium.com>
Wed, 28 May 2014 22:54:12 +0000 (22:54 +0000)
This patch addresses some aesthetic issues in Asterisk. These are all just
minor tweaks to improve the look of the CLI when used in a variety of
settings. Specifically:
 * A number of chatty verbose messages were removed or demoted to DEBUG
   messages. Verbose messages with a verbosity level of 5 or higher were -
   if kept as verbose messages - demoted to level 4. Several messages
   that were emitted at verbose level 3 were demoted to 4, as announcement
   of dialplan applications being executed occur at level 3 (and so the
   effects of those applications should generally be less).
 * Some verbose messages that only appear when their respective 'debug'
   options are enabled were bumped up to always be displayed.
 * Prefix/timestamping of verbose messages were moved to the verboser
   handlers. This was done to prevent duplication of prefixes when the
   timestamp option (-T) is used with the CLI.
 * Verbose magic is removed from messages before being emitted to
   non-verboser handlers. This prevents the magic in multi-line verbose
   messages (such as SIP debug traces or the output of DumpChan) from
   being written to files.
 * _Slightly_ better support for the "light background" option (-W) was
   added. This includes using ast_term_quit in the output of XML
   documentation help, as well as changing the "Asterisk Ready" prompt to
   bright green on the default background (which stands a better chance of
   being displayed properly than bright white).

Review: https://reviewboard.asterisk.org/r/3547/

git-svn-id: https://origsvn.digium.com/svn/asterisk/trunk@414798 65c4cc65-6c06-0410-ace0-fbb531ad65f3

27 files changed:
apps/app_mixmonitor.c
apps/app_voicemail.c
apps/app_waitforsilence.c
bridges/bridge_builtin_features.c
cdr/cdr_adaptive_odbc.c
cdr/cdr_odbc.c
cdr/cdr_pgsql.c
cdr/cdr_sqlite3_custom.c
cel/cel_odbc.c
cel/cel_pgsql.c
channels/chan_unistim.c
include/asterisk/logger.h
main/asterisk.c
main/bridge.c
main/config_options.c
main/loader.c
main/logger.c
main/optional_api.c
main/pbx.c
main/xmldoc.c
res/parking/parking_applications.c
res/res_config_curl.c
res/res_config_odbc.c
res/res_config_pgsql.c
res/res_fax.c
res/res_jabber.c
res/res_odbc.c

index 6a2a0fc..8013c8c 100644 (file)
@@ -502,7 +502,7 @@ static void add_vm_recipients_from_string(struct mixmonitor *mixmonitor, const c
                        ast_copy_string(recipient->folder, cur_folder, sizeof(recipient->folder));
 
                        /* Add to list */
-                       ast_verb(5, "Adding %s@%s to recipient list\n", recipient->mailbox, recipient->context);
+                       ast_verb(4, "Adding %s@%s to recipient list\n", recipient->mailbox, recipient->context);
                        AST_LIST_INSERT_HEAD(&mixmonitor->recipient_list, recipient, list);
                } else {
                        ast_log(LOG_ERROR, "Failed to properly parse extension and/or context from element %d of recipient string: %s\n", elements_processed, vm_recipients);
index cb85c5b..891d233 100644 (file)
@@ -7557,7 +7557,7 @@ static int get_folder(struct ast_channel *chan, int start)
                        if (ast_fileexists(fn, NULL, NULL)) {
                                d = vm_play_folder_name(chan, fn);
                        } else {
-                               ast_verb(1, "failed to find %s\n", fn);
+                               ast_verb(4, "Failed to find file %s; falling back to INBOX\n", fn);
                                d = vm_play_folder_name(chan, "vm-INBOX");
                        }
                } else {
index f792472..53870df 100644 (file)
@@ -179,7 +179,7 @@ static int do_waiting(struct ast_channel *chan, int timereqd, time_t waitstart,
                        ast_frfree(f);
                }
 
-               ast_verb(6, "Got %dms %s < %dms required\n", dsptime, wait_for_silence ? "silence" : "noise", timereqd);
+               ast_debug(1, "Got %dms %s < %dms required\n", dsptime, wait_for_silence ? "silence" : "noise", timereqd);
 
                if (dsptime >= timereqd) {
                        ast_verb(3, "Exiting with %dms %s >= %dms required\n", dsptime, wait_for_silence ? "silence" : "noise", timereqd);
index b300052..503de4c 100644 (file)
@@ -106,12 +106,12 @@ static enum set_touch_variables_res set_touch_variables(struct ast_channel *chan
 
 static void stop_automonitor(struct ast_bridge_channel *bridge_channel, struct ast_channel *peer_chan, struct ast_features_general_config *features_cfg, const char *stop_message)
 {
-       ast_verb(3, "AutoMonitor used to stop recording call.\n");
+       ast_verb(4, "AutoMonitor used to stop recording call.\n");
 
        ast_channel_lock(peer_chan);
        if (ast_channel_monitor(peer_chan)) {
                if (ast_channel_monitor(peer_chan)->stop(peer_chan, 1)) {
-                       ast_verb(3, "Cannot stop AutoMonitor for %s\n", ast_channel_name(bridge_channel->chan));
+                       ast_verb(4, "Cannot stop AutoMonitor for %s\n", ast_channel_name(bridge_channel->chan));
                        if (features_cfg && !(ast_strlen_zero(features_cfg->recordingfailsound))) {
                                ast_bridge_channel_queue_playfile(bridge_channel, NULL, features_cfg->recordingfailsound, NULL);
                        }
@@ -194,10 +194,10 @@ static void start_automonitor(struct ast_bridge_channel *bridge_channel, struct
                }
        }
 
-       ast_verb(3, "AutoMonitor used to record call. Filename: %s\n", touch_filename);
+       ast_verb(4, "AutoMonitor used to record call. Filename: %s\n", touch_filename);
 
        if (ast_monitor_start(peer_chan, touch_format, touch_filename, 1, X_REC_IN | X_REC_OUT, NULL)) {
-               ast_verb(3, "automon feature was tried by '%s' but monitor failed to start.\n",
+               ast_verb(4, "AutoMonitor feature was tried by '%s' but monitor failed to start.\n",
                        ast_channel_name(bridge_channel->chan));
                return;
        }
@@ -232,7 +232,7 @@ static int feature_automonitor(struct ast_bridge_channel *bridge_channel, void *
        ast_bridge_unlock(bridge_channel->bridge);
 
        if (!peer_chan) {
-               ast_verb(3, "Cannot start AutoMonitor for %s - can not determine peer in bridge.\n",
+               ast_verb(4, "Cannot start AutoMonitor for %s - can not determine peer in bridge.\n",
                        ast_channel_name(bridge_channel->chan));
                if (features_cfg && !ast_strlen_zero(features_cfg->recordingfailsound)) {
                        ast_bridge_channel_queue_playfile(bridge_channel, NULL, features_cfg->recordingfailsound, NULL);
@@ -263,14 +263,14 @@ static int feature_automonitor(struct ast_bridge_channel *bridge_channel, void *
                        start_automonitor(bridge_channel, peer_chan, features_cfg, start_message);
                        return 0;
                }
-               ast_verb(3, "AutoMonitor already recording call.\n");
+               ast_verb(4, "AutoMonitor already recording call.\n");
                break;
        case AUTO_MONITOR_STOP:
                if (is_monitoring) {
                        stop_automonitor(bridge_channel, peer_chan, features_cfg, stop_message);
                        return 0;
                }
-               ast_verb(3, "AutoMonitor already not recording call.\n");
+               ast_verb(4, "AutoMonitor already stopped on call.\n");
                break;
        }
 
@@ -295,10 +295,10 @@ static int feature_automonitor(struct ast_bridge_channel *bridge_channel, void *
 
 static void stop_automixmonitor(struct ast_bridge_channel *bridge_channel, struct ast_channel *peer_chan, struct ast_features_general_config *features_cfg, const char *stop_message)
 {
-       ast_verb(3, "AutoMixMonitor used to stop recording call.\n");
+       ast_verb(4, "AutoMixMonitor used to stop recording call.\n");
 
        if (ast_stop_mixmonitor(peer_chan, NULL)) {
-               ast_verb(3, "Failed to stop Mixmonitor for %s.\n", ast_channel_name(bridge_channel->chan));
+               ast_verb(4, "Failed to stop AutoMixMonitor for %s.\n", ast_channel_name(bridge_channel->chan));
                if (features_cfg && !(ast_strlen_zero(features_cfg->recordingfailsound))) {
                        ast_bridge_channel_queue_playfile(bridge_channel, NULL, features_cfg->recordingfailsound, NULL);
                }
@@ -375,10 +375,10 @@ static void start_automixmonitor(struct ast_bridge_channel *bridge_channel, stru
                }
        }
 
-       ast_verb(3, "AutoMixMonitor used to record call. Filename: %s\n", touch_filename);
+       ast_verb(4, "AutoMixMonitor used to record call. Filename: %s\n", touch_filename);
 
        if (ast_start_mixmonitor(peer_chan, touch_filename, "b")) {
-               ast_verb(3, "automixmon feature was tried by '%s' but mixmonitor failed to start.\n",
+               ast_verb(4, "AutoMixMonitor feature was tried by '%s' but MixMonitor failed to start.\n",
                        ast_channel_name(bridge_channel->chan));
 
                if (features_cfg && !ast_strlen_zero(features_cfg->recordingfailsound)) {
@@ -418,7 +418,7 @@ static int feature_automixmonitor(struct ast_bridge_channel *bridge_channel, voi
        ast_bridge_unlock(bridge_channel->bridge);
 
        if (!peer_chan) {
-               ast_verb(3, "Cannot do AutoMixMonitor for %s - cannot determine peer in bridge.\n",
+               ast_verb(4, "Cannot start AutoMixMonitor for %s - cannot determine peer in bridge.\n",
                        ast_channel_name(bridge_channel->chan));
                if (features_cfg && !ast_strlen_zero(features_cfg->recordingfailsound)) {
                        ast_bridge_channel_queue_playfile(bridge_channel, NULL, features_cfg->recordingfailsound, NULL);
@@ -450,14 +450,14 @@ static int feature_automixmonitor(struct ast_bridge_channel *bridge_channel, voi
                        start_automixmonitor(bridge_channel, peer_chan, features_cfg, start_message);
                        return 0;
                }
-               ast_verb(3, "AutoMixMonitor already recording call.\n");
+               ast_verb(4, "AutoMixMonitor already recording call.\n");
                break;
        case AUTO_MONITOR_STOP:
                if (is_monitoring) {
                        stop_automixmonitor(bridge_channel, peer_chan, features_cfg, stop_message);
                        return 0;
                }
-               ast_verb(3, "AutoMixMonitor already not recording call.\n");
+               ast_verb(4, "AutoMixMonitor already stopped on call.\n");
                break;
        }
 
index a5a8b85..72c2619 100644 (file)
@@ -196,7 +196,7 @@ static int load_config(void)
                                        ast_trim_blanks(cdrvar);
                                }
 
-                               ast_verb(3, "Found filter %s'%s' for cdr variable %s in %s@%s\n", negate ? "!" : "", var->value, cdrvar, tableptr->table, tableptr->connection);
+                               ast_verb(3, "Found filter %s'%s' for CDR variable %s in %s@%s\n", negate ? "!" : "", var->value, cdrvar, tableptr->table, tableptr->connection);
 
                                entry = ast_calloc(sizeof(char), sizeof(*entry) + strlen(cdrvar) + 1 + strlen(var->value) + 1);
                                if (!entry) {
@@ -281,7 +281,7 @@ static int load_config(void)
                        if (entry->octetlen == 0)
                                entry->octetlen = entry->size;
 
-                       ast_verb(10, "Found %s column with type %hd with len %ld, octetlen %ld, and numlen (%hd,%hd)\n", entry->name, entry->type, (long) entry->size, (long) entry->octetlen, entry->decimals, entry->radix);
+                       ast_verb(4, "Found %s column with type %hd with len %ld, octetlen %ld, and numlen (%hd,%hd)\n", entry->name, entry->type, (long) entry->size, (long) entry->octetlen, entry->decimals, entry->radix);
                        /* Insert column info into column list */
                        AST_LIST_INSERT_TAIL(&(tableptr->columns), entry, list);
                        res = 0;
@@ -723,7 +723,7 @@ static int odbc_log(struct ast_cdr *cdr)
                        } else if (entry->filtervalue
                                && ((!entry->negatefiltervalue && entry->filtervalue[0] != '\0')
                                        || (entry->negatefiltervalue && entry->filtervalue[0] == '\0'))) {
-                               ast_verb(4, "CDR column '%s' was not set and does not match filter of"
+                               ast_log(AST_LOG_WARNING, "CDR column '%s' was not set and does not match filter of"
                                        " %s'%s'.  Cancelling this CDR.\n",
                                        entry->cdrname, entry->negatefiltervalue ? "!" : "",
                                        entry->filtervalue);
@@ -737,7 +737,7 @@ static int odbc_log(struct ast_cdr *cdr)
                ast_str_append(&sql2, 0, ")");
                ast_str_append(&sql, 0, "%s", ast_str_buffer(sql2));
 
-               ast_verb(11, "[%s]\n", ast_str_buffer(sql));
+               ast_debug(3, "Executing [%s]\n", ast_str_buffer(sql));
 
                stmt = ast_odbc_prepare_and_execute(obj, generic_prepare, ast_str_buffer(sql));
                if (stmt) {
index be07a8a..2e86a06 100644 (file)
@@ -252,9 +252,6 @@ static int odbc_load_module(int reload)
                        break;
                }
 
-               ast_verb(3, "cdr_odbc: dsn is %s\n", dsn);
-               ast_verb(3, "cdr_odbc: table is %s\n", table);
-
                if (!ast_test_flag(&config, CONFIG_REGISTERED)) {
                        res = ast_cdr_register(name, ast_module_info->description, odbc_log);
                        if (res) {
@@ -290,11 +287,9 @@ static int unload_module(void)
        }
 
        if (dsn) {
-               ast_verb(11, "cdr_odbc: free dsn\n");
                ast_free(dsn);
        }
        if (table) {
-               ast_verb(11, "cdr_odbc: free table\n");
                ast_free(table);
        }
 
index 6ac3897..8322da9 100644 (file)
@@ -348,9 +348,8 @@ static int pgsql_log(struct ast_cdr *cdr)
                LENGTHEN_BUF1(ast_str_strlen(sql2) + 2);
                AST_RWLIST_UNLOCK(&psql_columns);
                ast_str_append(&sql, 0, ")%s)", ast_str_buffer(sql2));
-               ast_verb(11, "[%s]\n", ast_str_buffer(sql));
 
-               ast_debug(2, "inserting a CDR record.\n");
+               ast_debug(3, "Inserting a CDR record: [%s]\n", ast_str_buffer(sql));
 
                /* Test to be sure we're still connected... */
                /* If we're connected, and connection is working, good. */
@@ -691,7 +690,7 @@ static int config_module(int reload)
                                /* For varchar columns, the maximum length is encoded in a different field */
                                flen = PQgetvalue(result, i, 5);
                        }
-                       ast_verb(4, "Found column '%s' of type '%s'\n", fname, ftype);
+
                        cur = ast_calloc(1, sizeof(*cur) + strlen(fname) + strlen(ftype) + 2);
                        if (cur) {
                                sscanf(flen, "%30d", &cur->len);
index 83dac6a..435f4b3 100644 (file)
@@ -197,7 +197,7 @@ static int load_config(int reload)
                return -1;
        }
 
-       ast_verb(3, "cdr_sqlite3_custom: Logging CDR records to table '%s' in 'master.db'\n", table);
+       ast_verb(4, "cdr_sqlite3_custom: Logging CDR records to table '%s' in 'master.db'\n", table);
 
        ast_config_destroy(cfg);
 
index 87036bb..035857b 100644 (file)
@@ -761,8 +761,7 @@ static void odbc_log(struct ast_event *event)
                ast_str_append(&sql2, 0, ")");
                ast_str_append(&sql, 0, "%s", ast_str_buffer(sql2));
 
-               ast_verb(11, "[%s]\n", ast_str_buffer(sql));
-
+               ast_debug(3, "Executing SQL statement: [%s]\n", ast_str_buffer(sql));
                stmt = ast_odbc_prepare_and_execute(obj, generic_prepare, ast_str_buffer(sql));
                if (stmt) {
                        SQLRowCount(stmt, &rows);
index 7b1bd09..cd50af0 100644 (file)
@@ -288,9 +288,8 @@ static void pgsql_log(struct ast_event *event)
                AST_RWLIST_UNLOCK(&psql_columns);
                LENGTHEN_BUF1(ast_str_strlen(sql2) + 2);
                ast_str_append(&sql, 0, ")%s)", ast_str_buffer(sql2));
-               ast_verb(11, "[%s]\n", ast_str_buffer(sql));
 
-               ast_debug(2, "inserting a CEL record.\n");
+               ast_debug(3, "Inserting a CEL record: [%s].\n", ast_str_buffer(sql));
                /* Test to be sure we're still connected... */
                /* If we're connected, and connection is working, good. */
                /* Otherwise, attempt reconnect.  If it fails... sorry... */
index 6762db3..7525f39 100644 (file)
@@ -973,7 +973,7 @@ static void send_client(int size, const unsigned char *data, struct unistimsessi
 
 /*#ifdef DUMP_PACKET */
        if (unistimdebug) {
-               ast_verb(6, "Sending datas with seq #0x%.4x Using slot #%d :\n", (unsigned)pte->seq_server, buf_pos);
+               ast_verb(0, "Sending datas with seq #0x%.4x Using slot #%d :\n", (unsigned)pte->seq_server, buf_pos);
        }
 /*#endif */
        send_raw_client(pte->wsabufsend[buf_pos].len, pte->wsabufsend[buf_pos].buf, &(pte->sin),
@@ -986,7 +986,7 @@ static void send_ping(struct unistimsession *pte)
 {
        BUFFSEND;
        if (unistimdebug) {
-               ast_verb(6, "Sending ping\n");
+               ast_verb(0, "Sending ping\n");
        }
        pte->tick_next_ping = get_tick_count() + unistim_keepalive;
        memcpy(buffsend + SIZE_HEADER, packet_send_ping, sizeof(packet_send_ping));
@@ -1084,7 +1084,7 @@ static void check_send_queue(struct unistimsession *pte)
        /* Check if our send queue contained only one element */
        if (pte->last_buf_available == 1) {
                if (unistimdebug) {
-                       ast_verb(6, "Our single packet was ACKed.\n");
+                       ast_verb(0, "Our single packet was ACKed.\n");
                }
                pte->last_buf_available--;
                set_ping_timer(pte);
@@ -1093,14 +1093,14 @@ static void check_send_queue(struct unistimsession *pte)
        /* Check if this ACK catch up our latest packet */
        else if (pte->last_seq_ack + 1 == pte->seq_server + 1) {
                if (unistimdebug) {
-                       ast_verb(6, "Our send queue is completely ACKed.\n");
+                       ast_verb(0, "Our send queue is completely ACKed.\n");
                }
                pte->last_buf_available = 0;    /* Purge the send queue */
                set_ping_timer(pte);
                return;
        }
        if (unistimdebug) {
-               ast_verb(6, "We still have packets in our send queue\n");
+               ast_verb(0, "We still have packets in our send queue\n");
        }
        return;
 }
@@ -4659,7 +4659,7 @@ static void parsing(int size, unsigned char *buf, struct unistimsession *pte,
        if (buf[4] == 1) {
                ast_mutex_lock(&pte->lock);
                if (unistimdebug) {
-                       ast_verb(6, "ACK received for packet #0x%.4x\n", (unsigned)seq);
+                       ast_verb(0, "ACK received for packet #0x%.4x\n", (unsigned)seq);
                }
                pte->nb_retransmit = 0;
 
index eda5035..bd9c9c7 100644 (file)
@@ -263,6 +263,15 @@ int ast_logger_register_level(const char *name);
 void ast_logger_unregister_level(const char *name);
 
 /*!
+ * \brief Get the logger configured date format
+ *
+ * \retval The date format string
+ *
+ * \since 13.0.0
+ */
+const char *ast_logger_get_dateformat(void);
+
+/*!
  * \brief factory function to create a new uniquely identifying callid.
  *
  * \retval ast_callid struct pointer containing the call id
index a3bb881..213828c 100644 (file)
@@ -2068,13 +2068,14 @@ static void __remote_quit_handler(int num)
        sig_flags.need_quit = 1;
 }
 
-static const char *fix_header(char *outbuf, int maxout, const char *s, char level)
+static void set_header(char *outbuf, int maxout, char level)
 {
        const char *cmp;
+       char date[40];
 
        switch (level) {
-       case 0: *outbuf = '\0';
-               return s;
+       case 0: cmp = NULL;
+               break;
        case 1: cmp = VERBOSE_PREFIX_1;
                break;
        case 2: cmp = VERBOSE_PREFIX_2;
@@ -2085,12 +2086,20 @@ static const char *fix_header(char *outbuf, int maxout, const char *s, char leve
                break;
        }
 
-       if (!strncmp(s, cmp, strlen(cmp))) {
-               s += strlen(cmp);
+       if (ast_opt_timestamp) {
+               struct ast_tm tm;
+               struct timeval now = ast_tvnow();
+               ast_localtime(&now, &tm, NULL);
+               ast_strftime(date, sizeof(date), ast_logger_get_dateformat(), &tm);
        }
-       term_color(outbuf, cmp, COLOR_GRAY, 0, maxout);
 
-       return s;
+       snprintf(outbuf, maxout, "%s%s%s%s%s%s",
+               ast_opt_timestamp ? "[" : "",
+               ast_opt_timestamp ? date : "",
+               ast_opt_timestamp ? "] " : "",
+               cmp ? ast_term_color(COLOR_GRAY, 0) : "",
+               cmp ? cmp : "",
+               cmp ? ast_term_reset() : "");
 }
 
 struct console_state_data {
@@ -2118,16 +2127,15 @@ static int console_print(const char *s, int local)
 
        do {
                if (VERBOSE_HASMAGIC(s)) {
+
                        /* always use the given line's level, otherwise
                           we'll use the last line's level */
                        state->verbose_line_level = VERBOSE_MAGIC2LEVEL(s);
+
                        /* move past magic */
                        s++;
 
-                       if (local) {
-                               s = fix_header(prefix, sizeof(prefix), s,
-                                              state->verbose_line_level);
-                       }
+                       set_header(prefix, sizeof(prefix), state->verbose_line_level);
                } else {
                        *prefix = '\0';
                }
@@ -2149,7 +2157,7 @@ static int console_print(const char *s, int local)
                        continue;
                }
 
-               if (local && !ast_strlen_zero(prefix)) {
+               if (!ast_strlen_zero(prefix)) {
                        fputs(prefix, stdout);
                }
 
@@ -2572,8 +2580,6 @@ static char *show_license(struct ast_cli_entry *e, int cmd, struct ast_cli_args
 
 #define ASTERISK_PROMPT "*CLI> "
 
-#define ASTERISK_PROMPT2 "%s*CLI> "
-
 /*!
  * \brief Shutdown Asterisk CLI commands.
  *
@@ -2841,10 +2847,10 @@ static char *cli_prompt(EditLine *editline)
                        /* Force colors back to normal at end */
                        ast_term_color_code(&prompt, 0, 0);
                }
-       } else if (remotehostname) {
-               ast_str_set(&prompt, 0, ASTERISK_PROMPT2, remotehostname);
        } else {
-               ast_str_set(&prompt, 0, "%s", ASTERISK_PROMPT);
+               ast_str_set(&prompt, 0, "%s%s",
+                       remotehostname ? remotehostname : "",
+                       ASTERISK_PROMPT);
        }
 
        return ast_str_buffer(prompt);
@@ -4552,9 +4558,6 @@ int main(int argc, char *argv[])
 
        dnsmgr_start_refresh();
 
-       /* We might have the option of showing a console, but for now just
-          do nothing... */
-       ast_verb(0, COLORIZE_FMT "\n", COLORIZE(COLOR_BRWHITE, COLOR_BLACK, "Asterisk Ready."));
        if (ast_opt_no_fork) {
                consolethread = pthread_self();
        }
@@ -4581,6 +4584,8 @@ int main(int argc, char *argv[])
 
        run_startup_commands();
 
+       ast_verb(0, COLORIZE_FMT "\n", COLORIZE(COLOR_BRGREEN, 0, "Asterisk Ready."));
+
        if (ast_opt_console) {
                /* Console stuff now... */
                /* Register our quit function */
index fa4e3c6..dd68617 100644 (file)
@@ -2541,7 +2541,7 @@ static int try_swap_optimize_out(struct ast_bridge *chan_bridge,
 
                id = ast_atomic_fetchadd_int((int *) &optimization_id, +1);
 
-               ast_verb(3, "Move-swap optimizing %s <-- %s.\n",
+               ast_verb(4, "Move-swap optimizing %s <-- %s.\n",
                        ast_channel_name(dst_bridge_channel->chan),
                        ast_channel_name(other->chan));
 
@@ -2658,7 +2658,7 @@ static int try_merge_optimize_out(struct ast_bridge *chan_bridge,
                return 0;
        }
 
-       ast_verb(3, "Merge optimizing %s -- %s out.\n",
+       ast_verb(4, "Merge optimizing %s -- %s out.\n",
                ast_channel_name(chan_bridge_channel->chan),
                ast_channel_name(peer_bridge_channel->chan));
 
index a52a9da..ae40c62 100644 (file)
@@ -1191,7 +1191,7 @@ static void cli_show_module_options(struct ast_cli_args *a)
                                ast_cli(a->fd, "\n");
                        }
                        term_color(option_name, tmp->ref, COLOR_MAGENTA, COLOR_BLACK, sizeof(option_name));
-                       ast_cli(a->fd, "[%s%s]\n", option_name, term_end());
+                       ast_cli(a->fd, "[%s%s]\n", option_name, ast_term_reset());
                        if (ast_str_strlen(tmp->syntax)) {
                                ast_cli(a->fd, "%s\n", ast_xmldoc_printable(ast_str_buffer(tmp->syntax), 1));
                        }
index e40cbf3..d4e94a6 100644 (file)
@@ -185,7 +185,7 @@ void ast_module_register(const struct ast_module_info *info)
                mod = resource_being_loaded;
        }
 
-       ast_verb(5, "Registering module %s\n", info->name);
+       ast_debug(5, "Registering module %s\n", info->name);
 
        mod->info = info;
        AST_LIST_HEAD_INIT(&mod->users);
@@ -232,7 +232,7 @@ void ast_module_unregister(const struct ast_module_info *info)
        AST_LIST_UNLOCK(&module_list);
 
        if (mod) {
-               ast_verb(5, "Unregistering module %s\n", info->name);
+               ast_debug(5, "Unregistering module %s\n", info->name);
                AST_LIST_HEAD_DESTROY(&mod->users);
                ast_free(mod);
        }
@@ -440,20 +440,16 @@ static int is_module_loaded(const char *resource_name)
        char fn[PATH_MAX] = "";
        void *lib;
 
-       ast_verb(10, "Checking if %s is loaded\n", resource_name);
-
        snprintf(fn, sizeof(fn), "%s/%s", ast_config_AST_MODULE_DIR,
                resource_name);
 
        lib = dlopen(fn, RTLD_LAZY | RTLD_NOLOAD);
 
        if (lib) {
-               ast_verb(10, "  %s loaded\n", resource_name);
                logged_dlclose(resource_name, lib);
                return 1;
        }
 
-       ast_verb(10, "  %s not loaded\n", resource_name);
        return 0;
 }
 #endif
@@ -843,7 +839,7 @@ enum ast_module_reload_result ast_module_reload(const char *name)
        }
 
        if (ast_mutex_trylock(&reloadlock)) {
-               ast_verbose("The previous reload command didn't finish yet\n");
+               ast_verb(3, "The previous reload command didn't finish yet\n");
                res = AST_MODULE_RELOAD_IN_PROGRESS;
                goto module_reload_exit;
        }
@@ -859,7 +855,7 @@ enum ast_module_reload_result ast_module_reload(const char *name)
                        }
                }
                if (res != AST_LOCK_SUCCESS) {
-                       ast_verbose("Cannot grab lock on %s\n", ast_config_AST_CONFIG_DIR);
+                       ast_log(AST_LOG_WARNING, "Cannot grab lock on %s\n", ast_config_AST_CONFIG_DIR);
                        ast_mutex_unlock(&reloadlock);
                        res = AST_MODULE_RELOAD_ERROR;
                        goto module_reload_exit;
@@ -977,12 +973,7 @@ static enum ast_module_load_result start_resource(struct ast_module *mod)
        switch (res) {
        case AST_MODULE_LOAD_SUCCESS:
                if (!ast_fully_booted) {
-                       ast_verb(1, "%s => (%s)\n", mod->resource, term_color(tmp, mod->info->description, COLOR_BROWN, COLOR_BLACK, sizeof(tmp)));
-                       if (ast_opt_console && !option_verbose) {
-                               /* This never looks good on anything but the root console, so
-                                * it's best not to try to funnel it through the logger. */
-                               fprintf(stdout, ".");
-                       }
+                       ast_verb(2, "%s => (%s)\n", mod->resource, term_color(tmp, mod->info->description, COLOR_BROWN, COLOR_BLACK, sizeof(tmp)));
                } else {
                        ast_verb(1, "Loaded %s => (%s)\n", mod->resource, mod->info->description);
                }
index 2c0f3f4..16a044a 100644 (file)
@@ -235,6 +235,7 @@ static const int colors[NUMLOGLEVELS] = {
 };
 
 AST_THREADSTORAGE(verbose_buf);
+AST_THREADSTORAGE(verbose_build_buf);
 #define VERBOSE_BUF_INIT_SIZE   256
 
 AST_THREADSTORAGE(log_buf);
@@ -1171,25 +1172,50 @@ static void ast_log_vsyslog(struct logmsg *msg)
        syslog(syslog_level, "%s", buf);
 }
 
+static char *logger_strip_verbose_magic(const char *message, int level)
+{
+       char *p;
+       char *stripped_message = ast_strdup(message);
+       char magic = -(level + 1);
+
+       if (!stripped_message) {
+               return NULL;
+       }
+
+       do {
+               p = strchr(stripped_message, (char)magic);
+               if (p) {
+                       *p++ = ' ';
+               }
+       } while (p && *p);
+
+       return stripped_message;
+}
+
 /*! \brief Print a normal log message to the channels */
 static void logger_print_normal(struct logmsg *logmsg)
 {
        struct logchannel *chan = NULL;
        char buf[BUFSIZ];
        struct verb *v = NULL;
+       char *tmpmsg;
        int level = 0;
 
        if (logmsg->level == __LOG_VERBOSE) {
-               char *tmpmsg = ast_strdupa(logmsg->message + 1);
-
-               level = VERBOSE_MAGIC2LEVEL(logmsg->message);
 
                /* Iterate through the list of verbosers and pass them the log message string */
                AST_RWLIST_RDLOCK(&verbosers);
                AST_RWLIST_TRAVERSE(&verbosers, v, list)
                        v->verboser(logmsg->message);
                AST_RWLIST_UNLOCK(&verbosers);
-               ast_string_field_set(logmsg, message, tmpmsg);
+
+               level = VERBOSE_MAGIC2LEVEL(logmsg->message);
+
+               tmpmsg = logger_strip_verbose_magic(logmsg->message, level);
+               if (tmpmsg) {
+                       ast_string_field_set(logmsg, message, tmpmsg);
+                       ast_free(tmpmsg);
+               }
        }
 
        AST_RWLIST_RDLOCK(&logchannels);
@@ -1746,9 +1772,8 @@ void ast_log_backtrace(void)
 void __ast_verbose_ap(const char *file, int line, const char *func, int level, struct ast_callid *callid, const char *fmt, va_list ap)
 {
        const char *p;
-       struct ast_str *prefixed, *buf = NULL;
+       struct ast_str *prefixed, *buf;
        int res = 0;
-       const char *prefix = level >= 4 ? VERBOSE_PREFIX_4 : level == 3 ? VERBOSE_PREFIX_3 : level == 2 ? VERBOSE_PREFIX_2 : level == 1 ? VERBOSE_PREFIX_1 : "";
        signed char magic = level > 9 ? -10 : -level - 1; /* 0 => -1, 1 => -2, etc.  Can't pass NUL, as it is EOS-delimiter */
 
        /* For compatibility with modules still calling ast_verbose() directly instead of using ast_verb() */
@@ -1767,18 +1792,18 @@ void __ast_verbose_ap(const char *file, int line, const char *func, int level, s
        }
 
        if (!(prefixed = ast_str_thread_get(&verbose_buf, VERBOSE_BUF_INIT_SIZE)) ||
-           !(buf = ast_str_create(VERBOSE_BUF_INIT_SIZE))) {
+           !(buf = ast_str_thread_get(&verbose_build_buf, VERBOSE_BUF_INIT_SIZE))) {
                return;
        }
 
        res = ast_str_set_va(&buf, 0, fmt, ap);
        /* If the build failed then we can drop this allocated message */
        if (res == AST_DYNSTR_BUILD_FAILED) {
-               ast_free(buf);
                return;
        }
 
        ast_str_reset(prefixed);
+
        /* for every newline found in the buffer add verbose prefix data */
        fmt = ast_str_buffer(buf);
        do {
@@ -1787,22 +1812,12 @@ void __ast_verbose_ap(const char *file, int line, const char *func, int level, s
                }
                ++p;
 
-               if (ast_opt_timestamp) {
-                       struct ast_tm tm;
-                       char date[40];
-                       struct timeval now = ast_tvnow();
-                       ast_localtime(&now, &tm, NULL);
-                       ast_strftime(date, sizeof(date), dateformat, &tm);
-                       ast_str_append(&prefixed, 0, "%c[%s] %s", (char) magic, date, prefix);
-               } else {
-                       ast_str_append(&prefixed, 0, "%c%s", (char) magic, prefix);
-               }
+               ast_str_append(&prefixed, 0, "%c", (char)magic);
                ast_str_append_substr(&prefixed, 0, fmt, p - fmt);
                fmt = p;
        } while (p && *p);
 
        ast_log_callid(__LOG_VERBOSE, file, line, func, callid, "%s", ast_str_buffer(prefixed));
-       ast_free(buf);
 }
 
 void __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...)
@@ -2121,3 +2136,9 @@ void ast_logger_unregister_level(const char *name)
                AST_RWLIST_UNLOCK(&logchannels);
        }
 }
+
+const char *ast_logger_get_dateformat(void)
+{
+       return dateformat;
+}
+
index f9d5fc6..92f36ea 100644 (file)
@@ -135,7 +135,6 @@ static struct optional_api *optional_api_create(const char *symname)
        struct optional_api *api;
        size_t size;
 
-       ast_verb(6, "%s: building api object\n", symname);
        size = sizeof(*api) + strlen(symname) + 1;
        api = ast_std_calloc(1, size);
        if (!api) {
@@ -219,11 +218,8 @@ static void optional_api_user_relink(struct optional_api_user *user,
        struct optional_api *api)
 {
        if (api->impl && *user->optional_ref != api->impl) {
-               ast_verb(4, "%s: linking for %s\n", api->symname, user->module);
                *user->optional_ref = api->impl;
        } else if (!api->impl && *user->optional_ref != user->stub) {
-               ast_verb(4, "%s: stubbing for %s\n", api->symname,
-                       user->module);
                *user->optional_ref = user->stub;
        }
 }
@@ -252,8 +248,6 @@ void ast_optional_api_provide(const char *symname, ast_optional_fn impl)
 {
        struct optional_api *api;
 
-       ast_verb(4, "%s: providing\n", symname);
-
        api = get_api(symname);
        if (!api) {
                ast_log(LOG_ERROR, "%s: Allocation failed\n", symname);
@@ -268,8 +262,6 @@ void ast_optional_api_unprovide(const char *symname, ast_optional_fn impl)
 {
        struct optional_api *api;
 
-       ast_verb(4, "%s: un-providing\n", symname);
-
        api = get_api(symname);
        if (!api) {
                ast_log(LOG_ERROR, "%s: Could not find api\n", symname);
@@ -341,8 +333,6 @@ void ast_optional_api_unuse(const char *symname, ast_optional_fn *optional_ref,
 
                if (user->optional_ref == optional_ref) {
                        if (*user->optional_ref != user->stub) {
-                               ast_verb(4, "%s: stubbing for %s\n", symname,
-                                       module);
                                *user->optional_ref = user->stub;
                        }
 
index faddc47..0d0c7aa 100644 (file)
@@ -8613,7 +8613,6 @@ struct ast_context *ast_context_find_or_create(struct ast_context **extcontexts,
                *local_contexts = tmp;
                ast_hashtab_insert_safe(contexts_table, tmp); /*put this context into the tree */
                ast_unlock_contexts();
-               ast_debug(1, "Registered context '%s'(%p) in table %p registrar: %s\n", tmp->name, tmp, contexts_table, registrar);
                ast_verb(3, "Registered extension context '%s'; registrar: %s\n", tmp->name, registrar);
        } else {
                tmp->next = *local_contexts;
@@ -8621,7 +8620,6 @@ struct ast_context *ast_context_find_or_create(struct ast_context **extcontexts,
                        ast_hashtab_insert_immediate(exttable, tmp); /*put this context into the tree */
 
                *local_contexts = tmp;
-               ast_debug(1, "Registered context '%s'(%p) in local table %p; registrar: %s\n", tmp->name, tmp, exttable, registrar);
                ast_verb(3, "Registered extension context '%s'; registrar: %s\n", tmp->name, registrar);
        }
        return tmp;
@@ -11927,7 +11925,7 @@ int load_pbx(void)
        /* Initialize the PBX */
        ast_verb(1, "Asterisk PBX Core Initializing\n");
 
-       ast_verb(1, "Registering builtin applications:\n");
+       ast_verb(2, "Registering builtin applications and functions:\n");
        ast_cli_register_multiple(pbx_cli, ARRAY_LEN(pbx_cli));
        ast_data_register_multiple_core(pbx_data_providers, ARRAY_LEN(pbx_data_providers));
        __ast_custom_function_register(&exception_function, NULL);
@@ -11935,7 +11933,6 @@ int load_pbx(void)
 
        /* Register builtin applications */
        for (x = 0; x < ARRAY_LEN(builtins); x++) {
-               ast_verb(1, "[%s]\n", builtins[x].name);
                if (ast_register_application2(builtins[x].name, builtins[x].execute, NULL, NULL, NULL)) {
                        ast_log(LOG_ERROR, "Unable to register builtin application '%s'\n", builtins[x].name);
                        return -1;
index 431eb1d..28bea86 100644 (file)
@@ -432,7 +432,7 @@ char *ast_xmldoc_printable(const char *bwinput, int withcolors)
        }
 
        if (withcolors) {
-               ast_str_append(&colorized, 0, "%s", term_end());
+               ast_str_append(&colorized, 0, "%s", ast_term_reset());
                if (!colorized) {
                        return NULL;
                }
index 5500e33..51d6aff 100644 (file)
@@ -356,7 +356,7 @@ static int setup_park_common_datastore(struct ast_channel *parkee, const char *p
 
        if (!ast_strlen_zero(parker_dial_string)) {
                ast_channel_name_to_dial_string(parker_dial_string);
-               ast_verb(5, "Setting dial string to %s from %s value", parker_dial_string, attended_transfer ? "ATTENDEDTRANSFER" : "BLINDTRANSFER");
+               ast_verb(4, "Setting Parker dial string to %s from %s value", parker_dial_string, attended_transfer ? "ATTENDEDTRANSFER" : "BLINDTRANSFER");
                park_datastore->parker_dial_string = ast_strdup(parker_dial_string);
        }
 
index 9dfcb0d..660916a 100644 (file)
@@ -630,7 +630,7 @@ static int reload_module(void)
 static int unload_module(void)
 {
        ast_config_engine_deregister(&curl_engine);
-       ast_verb(1, "res_config_curl unloaded.\n");
+
        return 0;
 }
 
@@ -653,7 +653,7 @@ static int load_module(void)
        reload_module();
 
        ast_config_engine_register(&curl_engine);
-       ast_verb(1, "res_config_curl loaded.\n");
+
        return 0;
 }
 
index 4806bd2..dc46a98 100644 (file)
@@ -1205,14 +1205,13 @@ static int unload_module (void)
 {
        ast_config_engine_deregister(&odbc_engine);
 
-       ast_verb(1, "res_config_odbc unloaded.\n");
        return 0;
 }
 
 static int load_module (void)
 {
        ast_config_engine_register(&odbc_engine);
-       ast_verb(1, "res_config_odbc loaded.\n");
+
        return 0;
 }
 
index 58925a0..b8ab994 100644 (file)
@@ -1334,7 +1334,7 @@ static int load_module(void)
                return AST_MODULE_LOAD_DECLINE;
 
        ast_config_engine_register(&pgsql_engine);
-       ast_verb(1, "PostgreSQL RealTime driver loaded.\n");
+
        ast_cli_register_multiple(cli_realtime, ARRAY_LEN(cli_realtime));
 
        return 0;
@@ -1352,7 +1352,6 @@ static int unload_module(void)
        }
        ast_cli_unregister_multiple(cli_realtime, ARRAY_LEN(cli_realtime));
        ast_config_engine_deregister(&pgsql_engine);
-       ast_verb(1, "PostgreSQL RealTime unloaded.\n");
 
        /* Destroy cached table info */
        AST_LIST_LOCK(&psql_tables);
index 54fc9f1..aaf1d2a 100644 (file)
@@ -407,7 +407,7 @@ static void debug_check_frame_for_silence(struct ast_fax_session *s, unsigned in
                history->consec_ms = 0;
 
                if ((last_consec_frames != 0)) {
-                       ast_verb(6, "Channel '%s' fax session '%u', [ %.3ld.%.6ld ], %s sent %u frames (%u ms) of %s.\n",
+                       ast_verb(0, "Channel '%s' fax session '%u', [ %.3ld.%.6ld ], %s sent %u frames (%u ms) of %s.\n",
                                 s->channame, s->id, (long) diff.tv_sec, (long int) diff.tv_usec,
                                 (c2s) ? "channel" : "stack", last_consec_frames, last_consec_ms,
                                 (wassil) ? "silence" : "energy");
index dbc6135..d5079a6 100644 (file)
@@ -2627,7 +2627,7 @@ static void aji_handle_subscribe(struct aji_client *client, ikspak *pak)
                        ASTOBJ_UNREF(buddy, ast_aji_buddy_destroy);
                }
        default:
-               ast_verb(5, "JABBER: This is a subcription of type %i\n", pak->subtype);
+               ast_debug(3, "JABBER: This is a subcription of type %i\n", pak->subtype);
        }
 }
 
index 7b967d0..9cdcac3 100644 (file)
@@ -546,7 +546,7 @@ struct odbc_cache_tables *ast_odbc_find_table(const char *database, const char *
                                entry->octetlen = entry->size;
                        }
 
-                       ast_verb(10, "Found %s column with type %hd with len %ld, octetlen %ld, and numlen (%hd,%hd)\n", entry->name, entry->type, (long) entry->size, (long) entry->octetlen, entry->decimals, entry->radix);
+                       ast_debug(3, "Found %s column with type %hd with len %ld, octetlen %ld, and numlen (%hd,%hd)\n", entry->name, entry->type, (long) entry->size, (long) entry->octetlen, entry->decimals, entry->radix);
                        /* Insert column info into column list */
                        AST_LIST_INSERT_TAIL(&(tableptr->columns), entry, list);
                }