diff --git a/CHANGES b/CHANGES index 4b6e3d2fa7010f2df9250ef5e94292a5b600b1ec..b0a9eddbd03566a831e299bcc11b560a5495ad60 100644 --- 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 diff --git a/UPGRADE.txt b/UPGRADE.txt index 6fb9facc1735e0585bef46f6b256b806df3b01d6..d4c059bae5f50a7dc66e3ebd6c4a4abeaaa2a4a7 100644 --- a/UPGRADE.txt +++ b/UPGRADE.txt @@ -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. diff --git a/addons/res_config_mysql.c b/addons/res_config_mysql.c index f011e0d724b7aff4440747b986cb4432a2013ef8..0eac432c7675f88ad8171edd0c4c9288bb59e653 100644 --- a/addons/res_config_mysql.c +++ b/addons/res_config_mysql.c @@ -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; } diff --git a/codecs/codec_dahdi.c b/codecs/codec_dahdi.c index bca0256e35844a7ae87c827aad7d36d1e137cb6e..1a745a4173ba715f23f5fe9793b2a0378fd8b1dd 100644 --- a/codecs/codec_dahdi.c +++ b/codecs/codec_dahdi.c @@ -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; diff --git a/configs/logger.conf.sample b/configs/logger.conf.sample index af1f90c0b171c515540bc8ceb72964e0f0a4a98c..3f4850788b53153f832e59319f9bcbe43edf92b6 100644 --- a/configs/logger.conf.sample +++ b/configs/logger.conf.sample @@ -73,7 +73,7 @@ ; notice ; warning ; error -; verbose +; verbose(<level>) ; dtmf ; fax ; security @@ -93,6 +93,10 @@ ; 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 diff --git a/funcs/func_timeout.c b/funcs/func_timeout.c index d15e28f8dc3fadf17f26d7681edbc94b8c73ddec..0f5f369e5fd77a5fb6a95a40432f15e1b49e6ac1 100644 --- a/funcs/func_timeout.c +++ b/funcs/func_timeout.c @@ -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; diff --git a/include/asterisk/autoconfig.h.in b/include/asterisk/autoconfig.h.in index 1f3bed9824cf10c76787c907a85a7311c86f5bdb..0ba8ebaf7b938dca3389a09c2e802872b185f3ea 100644 --- a/include/asterisk/autoconfig.h.in +++ b/include/asterisk/autoconfig.h.in @@ -836,19 +836,19 @@ /* 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. */ @@ -1126,6 +1126,9 @@ /* 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 diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h index 9363caa748f773d80efbfb21aa7f13561fed31e9..8fdc97e65dc7c16b4c9fb544d2966689bc6d17b2 100644 --- a/include/asterisk/logger.h +++ b/include/asterisk/logger.h @@ -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 diff --git a/main/asterisk.c b/main/asterisk.c index ebc9a8a3fe012a071d38f677bbee5be3c96fb342..fd81462fb6bd5dbedf4377faa1e01e2c0c1332aa 100644 --- a/main/asterisk.c +++ b/main/asterisk.c @@ -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[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"); diff --git a/main/config.c b/main/config.c index 75aa4c7d7d8c0e70f95add7640dba5afa7115ac9..bec54cc7c11de101a8af6b5d2447456db65d4c4c 100644 --- a/main/config.c +++ b/main/config.c @@ -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)); diff --git a/main/loader.c b/main/loader.c index 6cd5ffbdbfd533fb63ea95389dda8e33d5e09531..f9b2de943372b44c33d3103c9d74bd3d9f9885a5 100644 --- a/main/loader.c +++ b/main/loader.c @@ -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); } diff --git a/main/logger.c b/main/logger.c index 6fc36df00de776da93bbf1b5260b7d233d28109f..74b7dd1901b6ae9727515d5f87a3125ba4a7e49e 100644 --- a/main/logger.c +++ b/main/logger.c @@ -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; } diff --git a/main/manager.c b/main/manager.c index 020ea913f91c0b8b27bd2abe842a7fd31de9d3fc..c538a29f000e0f8d722e50cafdc0c3e1c05fb74e 100644 --- a/main/manager.c +++ b/main/manager.c @@ -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)); } diff --git a/main/pbx.c b/main/pbx.c index dfb9e827be86e3b135a1670e6067fdde1dcb6241..436dc87da0fddf26b051d84daca05312739eb285 100644 --- a/main/pbx.c +++ b/main/pbx.c @@ -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, diff --git a/main/stdtime/localtime.c b/main/stdtime/localtime.c index 4e0fd760c990edfe0832f78d4581c74713161cda..dff06eedc12f3307925ba89481d651f7f67516d2 100644 --- a/main/stdtime/localtime.c +++ b/main/stdtime/localtime.c @@ -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) diff --git a/utils/ael_main.c b/utils/ael_main.c index 52aa47993300d28f364580df8ceab5c69d49a4fd..d3a23382a409caca03f483d4c3b7c123395a6844 100644 --- a/utils/ael_main.c +++ b/utils/ael_main.c @@ -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); diff --git a/utils/hashtest.c b/utils/hashtest.c index 390e331e02d3d6f533048a0e38fca3b05ff47184..c06d4ac0adadd353054f36bd5f4affa249d8c157 100644 --- a/utils/hashtest.c +++ b/utils/hashtest.c @@ -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); diff --git a/utils/hashtest2.c b/utils/hashtest2.c index 5bc62806159ad0647b2f4b2074923cbf47e7011b..47397101eb75ec64f05c27ddac08224f2a5a0722 100644 --- a/utils/hashtest2.c +++ b/utils/hashtest2.c @@ -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); diff --git a/utils/refcounter.c b/utils/refcounter.c index b45680e0d35bcd3b6a2e383a886368985dd22699..58cfa0de2ae487a1f75644dae4819a9cc5afdfeb 100644 --- a/utils/refcounter.c +++ b/utils/refcounter.c @@ -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);