Re-commit the verbose branch.
authorTilghman Lesher <tilghman@meg.abyt.es>
Tue, 14 Feb 2012 20:27:16 +0000 (20:27 +0000)
committerTilghman Lesher <tilghman@meg.abyt.es>
Tue, 14 Feb 2012 20:27:16 +0000 (20:27 +0000)
This change permits each verbose destination (consoles, logger) to have its
own concept of what the verbosity level is.  The big feature here is that
the logger will now be able to capture a particular verbosity level without
condemning each console to need to suffer that level of verbosity.
Additionally, a stray 'core set verbose' will no longer change what will go
to the log.

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

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

19 files changed:
CHANGES
UPGRADE.txt
addons/res_config_mysql.c
codecs/codec_dahdi.c
configs/logger.conf.sample
funcs/func_timeout.c
include/asterisk/autoconfig.h.in
include/asterisk/logger.h
main/asterisk.c
main/config.c
main/loader.c
main/logger.c
main/manager.c
main/pbx.c
main/stdtime/localtime.c
utils/ael_main.c
utils/hashtest.c
utils/hashtest2.c
utils/refcounter.c

diff --git a/CHANGES b/CHANGES
index 4b6e3d2..b0a9edd 100644 (file)
--- a/CHANGES
+++ b/CHANGES
@@ -147,6 +147,16 @@ DUNDi changes
  * Allow the built in variables ${NUMBER}, ${IPADDR} and ${SECRET} to be
    used within the dynamic weight attribute when specifying a mapping.
 
+Core changes
+------------
+ * Each logging destination and console now have an independent notion of the
+   current verbosity level.  Logger.conf now allows an optional argument to
+   the 'verbose' specifier, indicating the level of verbosity sent to that
+   particular logging destination.  Additionally, remote consoles now each
+   have their own verbosity level.  The command 'core set verbose' will now set
+   a separate level for each remote console without affecting any other
+   console.
+
 Dialplan functions
 ------------------
  * Addition of the VM_INFO function that can be used to retrieve voicemail
index 6fb9fac..d4c059b 100644 (file)
@@ -54,6 +54,10 @@ Configuration Files:
    - dnsmgr.conf
    - dsp.conf
 
+ - The 'verbose' setting in logger.conf now takes an optional argument,
+   specifying the verbosity level for each logging destination.  The default,
+   if not otherwise specified, is a verbosity of 3.
+
 AMI:
   - DBDelTree now correctly returns an error when 0 rows are deleted just as
     the DBDel action does.
index f011e0d..0eac432 100644 (file)
@@ -1417,11 +1417,7 @@ static int unload_module(void)
 static int reload(void)
 {
        parse_config(1);
-
-       if (option_verbose > 1) {
-               ast_verb(2, "MySQL RealTime reloaded.\n");
-       }
-
+       ast_verb(2, "MySQL RealTime reloaded.\n");
        return 0;
 }
 
index bca0256..1a745a4 100644 (file)
@@ -176,13 +176,11 @@ static void dahdi_write_frame(struct codec_dahdi_pvt *dahdip, const uint8_t *buf
        struct pollfd p = {0};
        if (!count) return;
        res = write(dahdip->fd, buffer, count);
-       if (option_verbose > 10) {
-               if (-1 == res) {
-                       ast_log(LOG_ERROR, "Failed to write to transcoder: %s\n", strerror(errno));
-               }
-               if (count != res) {
-                       ast_log(LOG_ERROR, "Requested write of %zd bytes, but only wrote %d bytes.\n", count, res);
-               }
+       if (-1 == res) {
+               ast_log(LOG_ERROR, "Failed to write to transcoder: %s\n", strerror(errno));
+       }
+       if (count != res) {
+               ast_log(LOG_ERROR, "Requested write of %zd bytes, but only wrote %d bytes.\n", count, res);
        }
        p.fd = dahdip->fd;
        p.events = POLLOUT;
index af1f90c..3f48507 100644 (file)
@@ -73,7 +73,7 @@
 ;    notice
 ;    warning
 ;    error
-;    verbose
+;    verbose(<level>)
 ;    dtmf
 ;    fax
 ;    security
 ; a filename; the "*" level means all levels, and the remaining level names
 ; will be ignored.
 ;
+; Verbose takes an additional argument, in the form of an integer level.
+; Messages with higher levels will be ignored.  If verbose is specified at
+; all, it will default to 3.
+;
 ; We highly recommend that you DO NOT turn on debug mode if you are simply
 ; running a production system.  Debug mode turns on a LOT of extra messages,
 ; most of which you are unlikely to understand without an understanding of
index d15e28f..0f5f369 100644 (file)
@@ -156,15 +156,13 @@ static int timeout_write(struct ast_channel *chan, const char *cmd, char *data,
        case 'a':
        case 'A':
                ast_channel_setwhentohangup_tv(chan, when);
-               if (VERBOSITY_ATLEAST(3)) {
-                       if (!ast_tvzero(chan->whentohangup)) {
-                               when = ast_tvadd(when, ast_tvnow());
-                               ast_strftime(timestr, sizeof(timestr), "%Y-%m-%d %H:%M:%S.%3q %Z",
-                                       ast_localtime(&when, &myt, NULL));
-                               ast_verbose("Channel will hangup at %s.\n", timestr);
-                       } else {
-                               ast_verbose("Channel hangup cancelled.\n");
-                       }
+               if (!ast_tvzero(chan->whentohangup)) {
+                       when = ast_tvadd(when, ast_tvnow());
+                       ast_strftime(timestr, sizeof(timestr), "%Y-%m-%d %H:%M:%S.%3q %Z",
+                               ast_localtime(&when, &myt, NULL));
+                       ast_verb(3, "Channel will hangup at %s.\n", timestr);
+               } else {
+                       ast_verb(3, "Channel hangup cancelled.\n");
                }
                break;
 
index 1f3bed9..0ba8eba 100644 (file)
 /* Define to 1 if you have the `strtoq' function. */
 #undef HAVE_STRTOQ
 
-/* Define to 1 if `ifr_ifru.ifru_hwaddr' is member of `struct ifreq'. */
+/* Define to 1 if `ifr_ifru.ifru_hwaddr' is a member of `struct ifreq'. */
 #undef HAVE_STRUCT_IFREQ_IFR_IFRU_IFRU_HWADDR
 
-/* Define to 1 if `uid' is member of `struct sockpeercred'. */
+/* Define to 1 if `uid' is a member of `struct sockpeercred'. */
 #undef HAVE_STRUCT_SOCKPEERCRED_UID
 
-/* Define to 1 if `st_blksize' is member of `struct stat'. */
+/* Define to 1 if `st_blksize' is a member of `struct stat'. */
 #undef HAVE_STRUCT_STAT_ST_BLKSIZE
 
-/* Define to 1 if `cr_uid' is member of `struct ucred'. */
+/* Define to 1 if `cr_uid' is a member of `struct ucred'. */
 #undef HAVE_STRUCT_UCRED_CR_UID
 
-/* Define to 1 if `uid' is member of `struct ucred'. */
+/* Define to 1 if `uid' is a member of `struct ucred'. */
 #undef HAVE_STRUCT_UCRED_UID
 
 /* Define to 1 if you have the mISDN Supplemental Services library. */
 /* Define to the one symbol short name of this package. */
 #undef PACKAGE_TARNAME
 
+/* Define to the home page for this package. */
+#undef PACKAGE_URL
+
 /* Define to the version of this package. */
 #undef PACKAGE_VERSION
 
index 9363caa..8fdc97e 100644 (file)
@@ -68,19 +68,20 @@ int logger_reload(void);
 void __attribute__((format(printf, 5, 6))) ast_queue_log(const char *queuename, const char *callid, const char *agent, const char *event, const char *fmt, ...);
 
 /*! Send a verbose message (based on verbose level)
-       \brief This works like ast_log, but prints verbose messages to the console depending on verbosity level set.
-       ast_verbose(VERBOSE_PREFIX_3 "Whatever %s is happening\n", "nothing");
-       This will print the message to the console if the verbose level is set to a level >= 3
-       Note the abscence of a comma after the VERBOSE_PREFIX_3.  This is important.
-       VERBOSE_PREFIX_1 through VERBOSE_PREFIX_3 are defined.
+ *     \brief This works like ast_log, but prints verbose messages to the console depending on verbosity level set.
+ *     ast_verbose(VERBOSE_PREFIX_3 "Whatever %s is happening\n", "nothing");
+ *     This will print the message to the console if the verbose level is set to a level >= 3
+ *     Note the absence of a comma after the VERBOSE_PREFIX_3.  This is important.
+ *     VERBOSE_PREFIX_1 through VERBOSE_PREFIX_4 are defined.
+ *  \version 11 added level parameter
  */
-void __attribute__((format(printf, 4, 5))) __ast_verbose(const char *file, int line, const char *func, const char *fmt, ...);
+void __attribute__((format(printf, 5, 6))) __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...);
 
-#define ast_verbose(...) __ast_verbose(__FILE__, __LINE__, __PRETTY_FUNCTION__,  __VA_ARGS__)
+#define ast_verbose(...) __ast_verbose(__FILE__, __LINE__, __PRETTY_FUNCTION__, -1, __VA_ARGS__)
 
-void __attribute__((format(printf, 4, 0))) __ast_verbose_ap(const char *file, int line, const char *func, const char *fmt, va_list ap);
+void __attribute__((format(printf, 5, 0))) __ast_verbose_ap(const char *file, int line, const char *func, int level, const char *fmt, va_list ap);
 
-#define ast_verbose_ap(fmt, ap)        __ast_verbose_ap(__FILE__, __LINE__, __PRETTY_FUNCTION__, fmt, ap)
+#define ast_verbose_ap(fmt, ap)        __ast_verbose_ap(__FILE__, __LINE__, __PRETTY_FUNCTION__, -1, fmt, ap)
 
 void __attribute__((format(printf, 2, 3))) ast_child_verbose(int level, const char *fmt, ...);
 
@@ -238,22 +239,7 @@ void ast_logger_unregister_level(const char *name);
                ast_log(AST_LOG_DEBUG, __VA_ARGS__); \
 } while (0)
 
-#define VERBOSITY_ATLEAST(level) (option_verbose >= (level) || (ast_opt_verb_module && ast_verbose_get_by_module(AST_MODULE) >= (level)))
-
-#define ast_verb(level, ...) do { \
-       if (VERBOSITY_ATLEAST((level)) ) { \
-               if (level >= 4) \
-                       ast_verbose(VERBOSE_PREFIX_4 __VA_ARGS__); \
-               else if (level == 3) \
-                       ast_verbose(VERBOSE_PREFIX_3 __VA_ARGS__); \
-               else if (level == 2) \
-                       ast_verbose(VERBOSE_PREFIX_2 __VA_ARGS__); \
-               else if (level == 1) \
-                       ast_verbose(VERBOSE_PREFIX_1 __VA_ARGS__); \
-               else \
-                       ast_verbose(__VA_ARGS__); \
-       } \
-} while (0)
+#define ast_verb(level, ...) __ast_verbose(__FILE__, __LINE__, __PRETTY_FUNCTION__, level, __VA_ARGS__)
 
 #ifndef _LOGGER_BACKTRACE_H
 #define _LOGGER_BACKTRACE_H
index ebc9a8a..fd81462 100644 (file)
@@ -1502,8 +1502,7 @@ static struct sigaction urg_handler = {
 static void _hup_handler(int num)
 {
        int a = 0, save_errno = errno;
-       if (option_verbose > 1) 
-               printf("Received HUP signal -- Reloading configs\n");
+       printf("Received HUP signal -- Reloading configs\n");
        if (restartnow)
                execvp(_argv[0], _argv);
        sig_flags.need_reload = 1;
@@ -1589,8 +1588,7 @@ int ast_set_priority(int pri)
                        ast_log(LOG_WARNING, "Unable to set high priority\n");
                        return -1;
                } else
-                       if (option_verbose)
-                               ast_verbose("Set to realtime thread\n");
+                       ast_verb(1, "Set to realtime thread\n");
        } else {
                sched.sched_priority = 0;
                /* According to the manpage, these parameters can never fail. */
@@ -1602,8 +1600,7 @@ int ast_set_priority(int pri)
                        ast_log(LOG_WARNING, "Unable to set high priority\n");
                        return -1;
                } else
-                       if (option_verbose)
-                               ast_verbose("Set to high priority\n");
+                       ast_verb(1, "Set to high priority\n");
        } else {
                /* According to the manpage, these parameters can never fail. */
                setpriority(PRIO_PROCESS, 0, 0);
@@ -1675,7 +1672,7 @@ static int can_safely_quit(shutdown_nice_t niceness, int restart)
                        ast_begin_shutdown(0);
                }
                if (option_verbose && ast_opt_console) {
-                       ast_verbose("Waiting for inactivity to perform %s...\n", restart ? "restart" : "halt");
+                       ast_verb(0, "Waiting for inactivity to perform %s...\n", restart ? "restart" : "halt");
                }
                for (;;) {
                        if (!ast_active_channels() || shuttingdown != niceness) {
@@ -1690,7 +1687,7 @@ static int can_safely_quit(shutdown_nice_t niceness, int restart)
        ast_mutex_lock(&safe_system_lock);
        if (shuttingdown != niceness) {
                if (shuttingdown == NOT_SHUTTING_DOWN && option_verbose && ast_opt_console) {
-                       ast_verbose("Asterisk %s cancelled.\n", restart ? "restart" : "shutdown");
+                       ast_verb(0, "Asterisk %s cancelled.\n", restart ? "restart" : "shutdown");
                }
                ast_mutex_unlock(&safe_system_lock);
                return 0;
@@ -1729,12 +1726,10 @@ static void really_quit(int num, shutdown_nice_t niceness, int restart)
                        }
                }
        }
-       if (option_verbose)
-               ast_verbose("Executing last minute cleanups\n");
+       ast_verb(0, "Executing last minute cleanups\n");
        ast_run_atexits();
        /* Called on exit */
-       if (option_verbose && ast_opt_console)
-               ast_verbose("Asterisk %s ending (%d).\n", ast_active_channels() ? "uncleanly" : "cleanly", num);
+       ast_verb(0, "Asterisk %s ending (%d).\n", ast_active_channels() ? "uncleanly" : "cleanly", num);
        ast_debug(1, "Asterisk ending (%d).\n", num);
        manager_event(EVENT_FLAG_SYSTEM, "Shutdown", "Shutdown: %s\r\nRestart: %s\r\n", ast_active_channels() ? "Uncleanly" : "Cleanly", restart ? "True" : "False");
        if (ast_socket > -1) {
@@ -1750,14 +1745,12 @@ static void really_quit(int num, shutdown_nice_t niceness, int restart)
        printf("%s", term_quit());
        if (restart) {
                int i;
-               if (option_verbose || ast_opt_console)
-                       ast_verbose("Preparing for Asterisk restart...\n");
+               ast_verb(0, "Preparing for Asterisk restart...\n");
                /* Mark all FD's for closing on exec */
                for (i = 3; i < 32768; i++) {
                        fcntl(i, F_SETFD, FD_CLOEXEC);
                }
-               if (option_verbose || ast_opt_console)
-                       ast_verbose("Asterisk is now restarting...\n");
+               ast_verb(0, "Asterisk is now restarting...\n");
                restartnow = 1;
 
                /* close logger */
@@ -1802,11 +1795,6 @@ static const char *fix_header(char *outbuf, int maxout, const char *s, char *cmp
 {
        const char *c;
 
-       /* Check for verboser preamble */
-       if (*s == 127) {
-               s++;
-       }
-
        if (!strncmp(s, cmp, strlen(cmp))) {
                c = s + strlen(cmp);
                term_color(outbuf, cmp, COLOR_GRAY, 0, maxout);
@@ -1815,10 +1803,25 @@ static const char *fix_header(char *outbuf, int maxout, const char *s, char *cmp
        return NULL;
 }
 
+/* These gymnastics are due to platforms which designate char as unsigned by
+ * default. Level is the negative character -- offset by 1, because \0 is the
+ * EOS delimiter. */
+#define VERBOSE_MAGIC2LEVEL(x) (((char) -*(signed char *) (x)) - 1)
+#define VERBOSE_HASMAGIC(x)    (*(signed char *) (x) < 0)
+
 static void console_verboser(const char *s)
 {
        char tmp[80];
        const char *c = NULL;
+       char level = 0;
+
+       if (VERBOSE_HASMAGIC(s)) {
+               level = VERBOSE_MAGIC2LEVEL(s);
+               s++;
+               if (level > option_verbose) {
+                       return;
+               }
+       }
 
        if ((c = fix_header(tmp, sizeof(tmp), s, VERBOSE_PREFIX_4)) ||
            (c = fix_header(tmp, sizeof(tmp), s, VERBOSE_PREFIX_3)) ||
@@ -1827,14 +1830,11 @@ static void console_verboser(const char *s)
                fputs(tmp, stdout);
                fputs(c, stdout);
        } else {
-               if (*s == 127) {
-                       s++;
-               }
                fputs(s, stdout);
        }
 
        fflush(stdout);
-       
+
        /* Wake up a poll()ing console */
        if (ast_opt_console && consolethread != AST_PTHREADT_NULL) {
                pthread_kill(consolethread, SIGURG);
@@ -1883,8 +1883,35 @@ static int remoteconsolehandler(char *s)
                else
                        ast_safe_system(getenv("SHELL") ? getenv("SHELL") : "/bin/sh");
                ret = 1;
-       }
-       if ((strncasecmp(s, "quit", 4) == 0 || strncasecmp(s, "exit", 4) == 0) &&
+       } else if (strncasecmp(s, "core set verbose ", 17) == 0) {
+               int old_verbose = option_verbose;
+               if (strncasecmp(s + 17, "atleast ", 8) == 0) {
+                       int tmp;
+                       if (sscanf(s + 25, "%d", &tmp) != 1) {
+                               fprintf(stderr, "Usage: core set verbose [atleast] <level>\n");
+                       } else {
+                               if (tmp > option_verbose) {
+                                       option_verbose = tmp;
+                               }
+                               if (old_verbose != option_verbose) {
+                                       fprintf(stdout, "Set remote console verbosity from %d to %d\n", old_verbose, option_verbose);
+                               } else {
+                                       fprintf(stdout, "Verbosity level unchanged.\n");
+                               }
+                       }
+               } else {
+                       if (sscanf(s + 17, "%d", &option_verbose) != 1) {
+                               fprintf(stderr, "Usage: core set verbose [atleast] <level>\n");
+                       } else {
+                               if (old_verbose != option_verbose) {
+                                       fprintf(stdout, "Set remote console verbosity to %d\n", option_verbose);
+                               } else {
+                                       fprintf(stdout, "Verbosity level unchanged.\n");
+                               }
+                       }
+               }
+               ret = 1;
+       } else if ((strncasecmp(s, "quit", 4) == 0 || strncasecmp(s, "exit", 4) == 0) &&
            (s[4] == '\0' || isspace(s[4]))) {
                quit_handler(0, SHUTDOWN_FAST, 0);
                ret = 1;
@@ -2198,6 +2225,23 @@ static struct ast_cli_entry cli_asterisk[] = {
 #endif /* ! LOW_MEMORY */
 };
 
+struct el_read_char_state_struct {
+       unsigned int line_full:1;
+       unsigned int prev_line_full:1;
+       char prev_line_verbosity;
+};
+
+static int el_read_char_state_init(void *ptr)
+{
+       struct el_read_char_state_struct *state = ptr;
+       state->line_full = 1;
+       state->prev_line_full = 1;
+       state->prev_line_verbosity = 0;
+       return 0;
+}
+
+AST_THREADSTORAGE_CUSTOM(el_read_char_state, el_read_char_state_init, ast_free_ptr);
+
 static int ast_el_read_char(EditLine *editline, char *cp)
 {
        int num_read = 0;
@@ -2207,6 +2251,7 @@ static int ast_el_read_char(EditLine *editline, char *cp)
        int max;
 #define EL_BUF_SIZE 512
        char buf[EL_BUF_SIZE];
+       struct el_read_char_state_struct *state = ast_threadstorage_get(&el_read_char_state, sizeof(*state));
 
        for (;;) {
                max = 1;
@@ -2236,7 +2281,8 @@ static int ast_el_read_char(EditLine *editline, char *cp)
                        }
                }
                if (fds[0].revents) {
-                       char *tmp;
+                       char level = 0;
+                       char *curline = buf, *nextline;
                        res = read(ast_consock, buf, sizeof(buf) - 1);
                        /* if the remote side disappears exit */
                        if (res < 1) {
@@ -2269,22 +2315,37 @@ static int ast_el_read_char(EditLine *editline, char *cp)
 
                        buf[res] = '\0';
 
-                       /* Strip preamble from asynchronous events, too */
-                       for (tmp = buf; *tmp; tmp++) {
-                               if (*tmp == 127) {
-                                       memmove(tmp, tmp + 1, strlen(tmp));
-                                       tmp--;
-                                       res--;
-                               }
-                       }
-
                        /* Write over the CLI prompt */
                        if (!ast_opt_exec && !lastpos) {
                                if (write(STDOUT_FILENO, "\r\e[0K", 5) < 0) {
                                }
                        }
-                       if (write(STDOUT_FILENO, buf, res) < 0) {
-                       }
+
+                       do {
+                               state->prev_line_full = state->line_full;
+                               if ((nextline = strchr(curline, '\n'))) {
+                                       state->line_full = 1;
+                                       nextline++;
+                               } else {
+                                       state->line_full = 0;
+                                       nextline = strchr(curline, '\0');
+                               }
+
+                               if (state->prev_line_full && VERBOSE_HASMAGIC(curline)) {
+                                       level = VERBOSE_MAGIC2LEVEL(curline);
+                                       curline++;
+                               } else {
+                                       level = state->prev_line_verbosity;
+                               }
+                               if ((!state->prev_line_full && state->prev_line_verbosity <= option_verbose) || (state->prev_line_full && level <= option_verbose)) {
+                                       if (write(STDOUT_FILENO, curline, nextline - curline) < 0) {
+                                       }
+                               }
+
+                               state->prev_line_verbosity = level;
+                               curline = nextline;
+                       } while (!ast_strlen_zero(curline));
+
                        if ((res < EL_BUF_SIZE - 1) && ((buf[res-1] == '\n') || (buf[res-2] == '\n'))) {
                                *cp = CC_REFRESH;
                                return(1);
@@ -2795,22 +2856,20 @@ static void ast_remotecontrol(char *data)
        else
                pid = -1;
        if (!data) {
-               char tmp[80];
-               snprintf(tmp, sizeof(tmp), "core set verbose atleast %d", option_verbose);
-               fdsend(ast_consock, tmp);
-               snprintf(tmp, sizeof(tmp), "core set debug atleast %d", option_debug);
-               fdsend(ast_consock, tmp);
-               if (!ast_opt_mute)
+               if (!ast_opt_mute) {
                        fdsend(ast_consock, "logger mute silent");
-               else 
+               } else {
                        printf("log and verbose output currently muted ('logger mute' to unmute)\n");
+               }
        }
 
        if (ast_opt_exec && data) {  /* hack to print output then exit if asterisk -rx is used */
+               int linefull = 1, prev_linefull = 1, prev_line_verbose = 0;
                struct pollfd fds;
                fds.fd = ast_consock;
                fds.events = POLLIN;
                fds.revents = 0;
+
                while (ast_poll(&fds, 1, 60000) > 0) {
                        char buffer[512] = "", *curline = buffer, *nextline;
                        int not_written = 1;
@@ -2824,18 +2883,34 @@ static void ast_remotecontrol(char *data)
                        }
 
                        do {
+                               prev_linefull = linefull;
                                if ((nextline = strchr(curline, '\n'))) {
+                                       linefull = 1;
                                        nextline++;
                                } else {
+                                       linefull = 0;
                                        nextline = strchr(curline, '\0');
                                }
 
                                /* Skip verbose lines */
-                               if (*curline != 127) {
+                               /* Prev line full? | Line is verbose | Last line verbose? | Print
+                                * TRUE            | TRUE*           | TRUE               | FALSE
+                                * TRUE            | TRUE*           | FALSE              | FALSE
+                                * TRUE            | FALSE*          | TRUE               | TRUE
+                                * TRUE            | FALSE*          | FALSE              | TRUE
+                                * FALSE           | TRUE            | TRUE*              | FALSE
+                                * FALSE           | TRUE            | FALSE*             | TRUE
+                                * FALSE           | FALSE           | TRUE*              | FALSE
+                                * FALSE           | FALSE           | FALSE*             | TRUE
+                                */
+                               if ((!prev_linefull && !prev_line_verbose) || (prev_linefull && *curline > 0)) {
+                                       prev_line_verbose = 0;
                                        not_written = 0;
                                        if (write(STDOUT_FILENO, curline, nextline - curline) < 0) {
                                                ast_log(LOG_WARNING, "write() failed: %s\n", strerror(errno));
                                        }
+                               } else {
+                                       prev_line_verbose = 1;
                                }
                                curline = nextline;
                        } while (!ast_strlen_zero(curline));
@@ -2874,14 +2949,6 @@ static void ast_remotecontrol(char *data)
                        if (ebuf[strlen(ebuf)-1] == '\n')
                                ebuf[strlen(ebuf)-1] = '\0';
                        if (!remoteconsolehandler(ebuf)) {
-                               /* Strip preamble from output */
-                               char *temp;
-                               for (temp = ebuf; *temp; temp++) {
-                                       if (*temp == 127) {
-                                               memmove(temp, temp + 1, strlen(temp));
-                                               temp--;
-                                       }
-                               }
                                res = write(ast_consock, ebuf, strlen(ebuf) + 1);
                                if (res < 1) {
                                        ast_log(LOG_WARNING, "Unable to write: %s\n", strerror(errno));
@@ -3580,8 +3647,7 @@ int main(int argc, char *argv[])
                        ast_log(LOG_WARNING, "Unable to drop unneeded groups\n");
                        exit(1);
                }
-               if (option_verbose)
-                       ast_verbose("Running as group '%s'\n", rungroup);
+               ast_verb(1, "Running as group '%s'\n", rungroup);
        }
 
        if (runuser && !ast_test_flag(&ast_options, AST_OPT_FLAG_REMOTE)) {
@@ -3621,8 +3687,7 @@ int main(int argc, char *argv[])
                        ast_log(LOG_WARNING, "Unable to setuid to %d (%s)\n", (int)pw->pw_uid, runuser);
                        exit(1);
                }
-               if (option_verbose)
-                       ast_verbose("Running as user '%s'\n", runuser);
+               ast_verb(1, "Running as user '%s'\n", runuser);
 #ifdef HAVE_CAP
                if (has_cap) {
                        cap_t cap;
@@ -3676,8 +3741,9 @@ int main(int argc, char *argv[])
        printf("%s", term_end());
        fflush(stdout);
 
-       if (ast_opt_console && !option_verbose) 
+       if (ast_opt_console && !option_verbose) {
                ast_verbose("[ Initializing Custom Configuration Options ]\n");
+       }
        /* custom config setup */
        register_config_cli();
        read_config_maps();
@@ -3952,15 +4018,14 @@ int main(int argc, char *argv[])
 
        /* We might have the option of showing a console, but for now just
           do nothing... */
-       if (ast_opt_console && !option_verbose)
-               ast_verbose(" ]\n");
-       if (option_verbose || ast_opt_console)
-               ast_verbose("%s", term_color(tmp, "Asterisk Ready.\n", COLOR_BRWHITE, COLOR_BLACK, sizeof(tmp)));
-       if (ast_opt_no_fork)
+       ast_verb(0, "%s\n", term_color(tmp, "Asterisk Ready.", COLOR_BRWHITE, COLOR_BLACK, sizeof(tmp)));
+       if (ast_opt_no_fork) {
                consolethread = pthread_self();
+       }
 
-       if (pipe(sig_alert_pipe))
+       if (pipe(sig_alert_pipe)) {
                sig_alert_pipe[0] = sig_alert_pipe[1] = -1;
+       }
 
        ast_set_flag(&ast_options, AST_OPT_FLAG_FULLY_BOOTED);
        manager_event(EVENT_FLAG_SYSTEM, "FullyBooted", "Status: Fully Booted\r\n");
index 75aa4c7..bec54cc 100644 (file)
@@ -1503,8 +1503,6 @@ static struct ast_config *config_text_file_load(const char *database, const char
                if (cfmtime)
                        cfmtime->mtime = statbuf.st_mtime;
 
-               ast_verb(2, "Parsing '%s': ", fn);
-                       fflush(stdout);
                if (!(f = fopen(fn, "r"))) {
                        ast_debug(1, "No file to parse: %s\n", fn);
                        ast_verb(2, "Parsing '%s': Not found (%s)\n", fn, strerror(errno));
index 6cd5ffb..f9b2de9 100644 (file)
@@ -797,8 +797,11 @@ static enum ast_module_load_result start_resource(struct ast_module *mod)
        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)
-                               ast_verbose( ".");
+                       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, ".");
+                       }
                } else {
                        ast_verb(1, "Loaded %s => (%s)\n", mod->resource, mod->info->description);
                }
index 6fc36df..74b7dd1 100644 (file)
@@ -101,6 +101,8 @@ struct logchannel {
        int disabled;
        /*! syslog facility */
        int facility;
+       /*! Verbosity level */
+       int verbosity;
        /*! Type of log channel */
        enum logtypes type;
        /*! logfile logging file pointer */
@@ -209,19 +211,24 @@ AST_THREADSTORAGE(log_buf);
 
 static void logger_queue_init(void);
 
-static unsigned int make_components(const char *s, int lineno)
+static unsigned int make_components(const char *s, int lineno, int *verbosity)
 {
        char *w;
        unsigned int res = 0;
        char *stringp = ast_strdupa(s);
        unsigned int x;
 
+       *verbosity = 3;
+
        while ((w = strsep(&stringp, ","))) {
                w = ast_skip_blanks(w);
 
                if (!strcmp(w, "*")) {
                        res = 0xFFFFFFFF;
                        break;
+               } else if (!strncasecmp(w, "verbose(", 8) && sscanf(w + 8, "%d)", verbosity) == 1) {
+                       res |= (1 << __LOG_VERBOSE);
+                       break;
                } else for (x = 0; x < ARRAY_LEN(levels); x++) {
                        if (levels[x] && !strcasecmp(w, levels[x])) {
                                res |= (1 << x);
@@ -300,7 +307,7 @@ static struct logchannel *make_logchannel(const char *channel, const char *compo
                }
                chan->type = LOGTYPE_FILE;
        }
-       chan->logmask = make_components(chan->components, lineno);
+       chan->logmask = make_components(chan->components, lineno, &chan->verbosity);
 
        return chan;
 }
@@ -434,11 +441,6 @@ void ast_child_verbose(int level, const char *fmt, ...)
        va_list ap, aq;
        int size;
 
-       /* Don't bother, if the level isn't that high */
-       if (option_verbose < level) {
-               return;
-       }
-
        va_start(ap, fmt);
        va_copy(aq, ap);
        if ((size = vsnprintf(msg, 0, fmt, ap)) < 0) {
@@ -968,15 +970,23 @@ static void ast_log_vsyslog(struct logmsg *msg)
        syslog(syslog_level, "%s", buf);
 }
 
+/* These gymnastics are due to platforms which designate char as unsigned by
+ * default. Level is the negative character -- offset by 1, because \0 is the
+ * EOS delimiter. */
+#define VERBOSE_MAGIC2LEVEL(x) (((char) -*(signed char *) (x)) - 1)
+#define VERBOSE_HASMAGIC(x)    (*(signed char *) (x) < 0)
+
 /*! \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;
+       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)
@@ -990,8 +1000,13 @@ static void logger_print_normal(struct logmsg *logmsg)
        if (!AST_RWLIST_EMPTY(&logchannels)) {
                AST_RWLIST_TRAVERSE(&logchannels, chan, list) {
                        /* If the channel is disabled, then move on to the next one */
-                       if (chan->disabled)
+                       if (chan->disabled) {
+                               continue;
+                       }
+                       if (logmsg->level == __LOG_VERBOSE && level > chan->verbosity) {
                                continue;
+                       }
+
                        /* Check syslog channels */
                        if (chan->type == LOGTYPE_SYSLOG && (chan->logmask & (1 << logmsg->level))) {
                                ast_log_vsyslog(logmsg);
@@ -1219,20 +1234,11 @@ void ast_log(int level, const char *file, int line, const char *function, const
                }
                return;
        }
-       
-       /* don't display LOG_DEBUG messages unless option_verbose _or_ option_debug
-          are non-zero; LOG_DEBUG messages can still be displayed if option_debug
-          is zero, if option_verbose is non-zero (this allows for 'level zero'
-          LOG_DEBUG messages to be displayed, if the logmask on any channel
-          allows it)
-       */
-       if (!option_verbose && !option_debug && (level == __LOG_DEBUG))
-               return;
 
        /* Ignore anything that never gets logged anywhere */
        if (level != __LOG_VERBOSE && !(global_logmask & (1 << level)))
                return;
-       
+
        /* Build string */
        va_start(ap, fmt);
        res = ast_str_set_va(&buf, BUFSIZ, fmt, ap);
@@ -1492,13 +1498,31 @@ void ast_backtrace(void)
 #endif /* defined(HAVE_BKTR) */
 }
 
-void __ast_verbose_ap(const char *file, int line, const char *func, const char *fmt, va_list ap)
+void __ast_verbose_ap(const char *file, int line, const char *func, int level, const char *fmt, va_list ap)
 {
        struct ast_str *buf = NULL;
        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 > 127 ? -128 : -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() */
+       if (level < 0) {
+               if (!strncmp(fmt, VERBOSE_PREFIX_4, strlen(VERBOSE_PREFIX_4))) {
+                       magic = -5;
+               } else if (!strncmp(fmt, VERBOSE_PREFIX_3, strlen(VERBOSE_PREFIX_3))) {
+                       magic = -4;
+               } else if (!strncmp(fmt, VERBOSE_PREFIX_2, strlen(VERBOSE_PREFIX_2))) {
+                       magic = -3;
+               } else if (!strncmp(fmt, VERBOSE_PREFIX_1, strlen(VERBOSE_PREFIX_1))) {
+                       magic = -2;
+               } else {
+                       magic = -1;
+               }
+       }
 
-       if (!(buf = ast_str_thread_get(&verbose_buf, VERBOSE_BUF_INIT_SIZE)))
+       if (!(buf = ast_str_thread_get(&verbose_buf, VERBOSE_BUF_INIT_SIZE))) {
                return;
+       }
 
        if (ast_opt_timestamp) {
                struct timeval now;
@@ -1509,12 +1533,12 @@ void __ast_verbose_ap(const char *file, int line, const char *func, const char *
                now = ast_tvnow();
                ast_localtime(&now, &tm, NULL);
                ast_strftime(date, sizeof(date), dateformat, &tm);
-               datefmt = alloca(strlen(date) + 3 + strlen(fmt) + 1);
-               sprintf(datefmt, "%c[%s] %s", 127, date, fmt);
+               datefmt = alloca(strlen(date) + 3 + strlen(prefix) + strlen(fmt) + 1);
+               sprintf(datefmt, "%c[%s] %s%s", (char) magic, date, prefix, fmt);
                fmt = datefmt;
        } else {
-               char *tmp = alloca(strlen(fmt) + 2);
-               sprintf(tmp, "%c%s", 127, fmt);
+               char *tmp = alloca(strlen(prefix) + strlen(fmt) + 2);
+               sprintf(tmp, "%c%s%s", (char) magic, prefix, fmt);
                fmt = tmp;
        }
 
@@ -1522,18 +1546,19 @@ void __ast_verbose_ap(const char *file, int line, const char *func, const char *
        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)
+       if (res == AST_DYNSTR_BUILD_FAILED) {
                return;
+       }
 
        ast_log(__LOG_VERBOSE, file, line, func, "%s", ast_str_buffer(buf));
 }
 
-void __ast_verbose(const char *file, int line, const char *func, const char *fmt, ...)
+void __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...)
 {
        va_list ap;
 
        va_start(ap, fmt);
-       __ast_verbose_ap(file, line, func, fmt, ap);
+       __ast_verbose_ap(file, line, func, level, fmt, ap);
        va_end(ap);
 }
 
@@ -1545,7 +1570,7 @@ void ast_verbose(const char *fmt, ...)
        va_list ap;
 
        va_start(ap, fmt);
-       __ast_verbose_ap("", 0, "", fmt, ap);
+       __ast_verbose_ap("", 0, "", 0, fmt, ap);
        va_end(ap);
 }
 
@@ -1592,7 +1617,7 @@ static void update_logchannels(void)
        global_logmask = 0;
 
        AST_RWLIST_TRAVERSE(&logchannels, cur, list) {
-               cur->logmask = make_components(cur->components, cur->lineno);
+               cur->logmask = make_components(cur->components, cur->lineno, &cur->verbosity);
                global_logmask |= cur->logmask;
        }
 
index 020ea91..c538a29 100644 (file)
@@ -5123,7 +5123,7 @@ static void purge_sessions(int n_max)
        while ((session = ao2_iterator_next(&i)) && n_max > 0) {
                ao2_lock(session);
                if (session->sessiontimeout && (now > session->sessiontimeout) && !session->inuse) {
-                       if (session->authenticated && (VERBOSITY_ATLEAST(2)) && manager_displayconnects(session)) {
+                       if (session->authenticated && manager_displayconnects(session)) {
                                ast_verb(2, "HTTP Manager '%s' timed out from %s\n",
                                        session->username, ast_inet_ntoa(session->sin.sin_addr));
                        }
index dfb9e82..436dc87 100644 (file)
@@ -4369,7 +4369,7 @@ static int pbx_extension_helper(struct ast_channel *c, struct ast_context *con,
                        ast_channel_trace_update(c);
 #endif
                        ast_debug(1, "Launching '%s'\n", app->name);
-                       if (VERBOSITY_ATLEAST(3)) {
+                       {
                                char tmp[80], tmp2[80], tmp3[EXT_DATA_SIZE];
                                ast_verb(3, "Executing [%s@%s:%d] %s(\"%s\", \"%s\") %s\n",
                                        exten, context, priority,
index 4e0fd76..dff06ee 100644 (file)
@@ -261,6 +261,19 @@ static AST_LIST_HEAD_STATIC(localelist, locale_entry);
 static pthread_t inotify_thread = AST_PTHREADT_NULL;
 static ast_cond_t initialization;
 static ast_mutex_t initialization_lock;
+
+static void add_notify(struct state *sp, const char *path);
+
+/*! Start a notification for every entry already in the list. */
+static void common_startup(void) {
+       struct state *sp;
+       AST_LIST_LOCK(&zonelist);
+       AST_LIST_TRAVERSE(&zonelist, sp, list) {
+               add_notify(sp, sp->name);
+       }
+       AST_LIST_UNLOCK(&zonelist);
+}
+
 #ifdef HAVE_INOTIFY
 static int inotify_fd = -1;
 
@@ -285,6 +298,8 @@ static void *inotify_daemon(void *data)
                return NULL;
        }
 
+       common_startup();
+
        for (;/*ever*/;) {
                /* This read should block, most of the time. */
                if ((res = read(inotify_fd, &buf, sizeof(buf))) < sizeof(buf.iev) && res > 0) {
@@ -378,6 +393,8 @@ static void *kqueue_daemon(void *data)
        ast_cond_signal(&initialization);
        ast_mutex_unlock(&initialization_lock);
 
+       common_startup();
+
        for (;/*ever*/;) {
                if (kevent(queue_fd, NULL, 0, &kev, 1, NULL) < 0) {
                        AST_LIST_LOCK(&zonelist);
@@ -538,6 +555,8 @@ static void *notify_daemon(void *data)
        ast_cond_broadcast(&initialization);
        ast_mutex_unlock(&initialization_lock);
 
+       common_startup();
+
        for (;/*ever*/;) {
                char            fullname[FILENAME_MAX + 1];
 
@@ -703,7 +722,14 @@ static int tzload(const char *name, struct state * const sp, const int doextend)
                        return -1;
                if ((fid = open(name, OPEN_MODE)) == -1)
                        return -1;
-               add_notify(sp, name);
+               if (ast_fully_booted) {
+                       /* If we don't wait until Asterisk is fully booted, it's possible
+                        * that the watcher thread gets started in the parent process,
+                        * before daemon(3) is called, and the thread won't propagate to
+                        * the child.  Given that bootup only takes a few seconds, it's
+                        * reasonable to only start the watcher later. */
+                       add_notify(sp, name);
+               }
        }
        nread = read(fid, u.buf, sizeof u.buf);
        if (close(fid) < 0 || nread <= 0)
index 52aa479..d3a2338 100644 (file)
@@ -122,7 +122,7 @@ void ast_cli_unregister_multiple(void);
 void ast_context_destroy(void);
 void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...);
 char *ast_process_quotes_and_slashes(char *start, char find, char replace_with);
-void __ast_verbose(const char *file, int line, const char *func, const char *fmt, ...);
+void __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...);
 struct ast_app *pbx_findapp(const char *app);
 void filter_leading_space_from_exprs(char *str);
 void filter_newlines(char *str);
index 390e331..c06d4ac 100644 (file)
@@ -356,7 +356,7 @@ void ast_log(int level, const char *file, int line, const char *function, const
        va_end(vars);
 }
 
-void __ast_verbose(const char *file, int line, const char *func, const char *fmt, ...)
+void __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...)
 {
         va_list vars;
         va_start(vars,fmt);
index 5bc6280..4739710 100644 (file)
@@ -368,7 +368,7 @@ void ast_log(int level, const char *file, int line, const char *function, const
        va_end(vars);
 }
 
-void __ast_verbose(const char *file, int line, const char *func, const char *fmt, ...)
+void __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...)
 {
         va_list vars;
         va_start(vars,fmt);
index b45680e..58cfa0d 100644 (file)
@@ -259,7 +259,7 @@ void ast_log(int level, const char *file, int line, const char *function, const
        va_end(vars);
 }
 
-void __ast_verbose(const char *file, int line, const char *func, const char *fmt, ...)
+void __ast_verbose(const char *file, int line, const char *func, int level, const char *fmt, ...)
 {
         va_list vars;
         va_start(vars,fmt);