Backed out core changes from r346391

During testing, it was discovered that there were a number of side effects
introduced by r346391 and subsequent check-ins related to it (r346429,
r346617, and r346655).  This included the /main/stdtime/ test 'hanging',
as well as the remote console option failing to receive the appropriate output
after a period of time.

I only backed out the changes to main/ and utils/, as this was adequate
to reverse the behavior experienced.

(issue ASTERISK-18974)

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

5 files changed, 72 insertions, 179 deletions

diff --git a/main/asterisk.c b/main/asterisk.c
index 48baa2a3d..48192758c 100644
--- a/main/asterisk.c
+++ b/main/asterisk.c
@@ -1751,6 +1751,11 @@ 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);
@@ -1759,25 +1764,10 @@ 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)) ||
@@ -1786,11 +1776,14 @@ 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);
@@ -1839,26 +1832,8 @@ static int remoteconsolehandler(char *s)
 		else
 			ast_safe_system(getenv("SHELL") ? getenv("SHELL") : "/bin/sh");
 		ret = 1;
-	} else if (strncasecmp(s, "remote set verbose ", 19) == 0) {
-		if (strncasecmp(s + 19, "atleast ", 8) == 0) {
-			int tmp;
-			if (sscanf(s + 27, "%d", &tmp) != 1) {
-				fprintf(stderr, "Usage: remote set verbose [atleast] <level>\n");
-			} else {
-				if (tmp > option_verbose) {
-					option_verbose = tmp;
-				}
-				fprintf(stdout, "Set remote console verbosity to %d\n", option_verbose);
-			}
-		} else {
-			if (sscanf(s + 19, "%d", &option_verbose) != 1) {
-				fprintf(stderr, "Usage: remote set verbose [atleast] <level>\n");
-			} else {
-				fprintf(stdout, "Set remote console verbosity to %d\n", option_verbose);
-			}
-		}
-		ret = 1;
-	} else if ((strncasecmp(s, "quit", 4) == 0 || strncasecmp(s, "exit", 4) == 0) &&
+	}
+	if ((strncasecmp(s, "quit", 4) == 0 || strncasecmp(s, "exit", 4) == 0) &&
 	    (s[4] == '\0' || isspace(s[4]))) {
 		quit_handler(0, 0, 0, 0);
 		ret = 1;
@@ -2161,23 +2136,6 @@ 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;
@@ -2187,7 +2145,6 @@ 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;
@@ -2217,8 +2174,7 @@ static int ast_el_read_char(EditLine *editline, char *cp)
 			}
 		}
 		if (fds[0].revents) {
-			char level = 0;
-			char *curline = buf, *nextline;
+			char *tmp;
 			res = read(ast_consock, buf, sizeof(buf) - 1);
 			/* if the remote side disappears exit */
 			if (res < 1) {
@@ -2251,37 +2207,22 @@ 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", 5) < 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 (write(STDOUT_FILENO, buf, res) < 0) {
+			}
 			if ((res < EL_BUF_SIZE - 1) && ((buf[res-1] == '\n') || (buf[res-2] == '\n'))) {
 				*cp = CC_REFRESH;
 				return(1);
@@ -2792,20 +2733,22 @@ static void ast_remotecontrol(char *data)
 	else
 		pid = -1;
 	if (!data) {
-		if (!ast_opt_mute) {
+		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)
 			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;
@@ -2819,34 +2762,18 @@ 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 */
-				/* 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;
+				if (*curline != 127) {
 					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));
@@ -2885,6 +2812,14 @@ 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));
diff --git a/main/cli.c b/main/cli.c
index 9c66b6767..c35b941d1 100644
--- a/main/cli.c
+++ b/main/cli.c
@@ -382,20 +382,6 @@ static char *complete_number(const char *partial, unsigned int min, unsigned int
 	return NULL;
 }
 
-static char *handle_localverbose(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
-{
-	switch (cmd) {
-	case CLI_INIT:
-		e->command = "remote set verbose";
-		e->usage = "Usage: remote set verbose <level>\n";
-		return NULL;
-	case CLI_GENERATE:
-		return NULL;
-	}
-	ast_cli(a->fd, "This is the main console.  Use 'core set verbose' instead.\n");
-	return CLI_FAILURE;
-}
-
 static char *handle_verbose(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
 {
 	int oldval;
@@ -1682,8 +1668,6 @@ static struct ast_cli_entry cli_cli[] = {
 
 	AST_CLI_DEFINE(handle_showchan, "Display information on a specific channel"),
 
-	AST_CLI_DEFINE(handle_localverbose, "Set level of remote console verbosity"),
-
 	AST_CLI_DEFINE(handle_core_set_debug_channel, "Enable/disable debugging on a channel"),
 
 	AST_CLI_DEFINE(handle_verbose, "Set level of debug/verbose chattiness"),
diff --git a/main/config.c b/main/config.c
index 9c0f73ac9..a527f2433 100644
--- a/main/config.c
+++ b/main/config.c
@@ -1503,6 +1503,8 @@ 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 f9b2de943..6cd5ffbdb 100644
--- a/main/loader.c
+++ b/main/loader.c
@@ -797,11 +797,8 @@ 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) {
-				/* 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, ".");
-			}
+			if (ast_opt_console && !option_verbose)
+				ast_verbose( ".");
 		} else {
 			ast_verb(1, "Loaded %s => (%s)\n", mod->resource, mod->info->description);
 		}
diff --git a/main/logger.c b/main/logger.c
index 74b7dd190..6fc36df00 100644
--- a/main/logger.c
+++ b/main/logger.c
@@ -101,8 +101,6 @@ struct logchannel {
 	int disabled;
 	/*! syslog facility */
 	int facility;
-	/*! Verbosity level */
-	int verbosity;
 	/*! Type of log channel */
 	enum logtypes type;
 	/*! logfile logging file pointer */
@@ -211,24 +209,19 @@ AST_THREADSTORAGE(log_buf);
 
 static void logger_queue_init(void);
 
-static unsigned int make_components(const char *s, int lineno, int *verbosity)
+static unsigned int make_components(const char *s, int lineno)
 {
 	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);
@@ -307,7 +300,7 @@ static struct logchannel *make_logchannel(const char *channel, const char *compo
 		}
 		chan->type = LOGTYPE_FILE;
 	}
-	chan->logmask = make_components(chan->components, lineno, &chan->verbosity);
+	chan->logmask = make_components(chan->components, lineno);
 
 	return chan;
 }
@@ -441,6 +434,11 @@ 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) {
@@ -970,23 +968,15 @@ 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)
@@ -1000,13 +990,8 @@ 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) {
-				continue;
-			}
-			if (logmsg->level == __LOG_VERBOSE && level > chan->verbosity) {
+			if (chan->disabled)
 				continue;
-			}
-
 			/* Check syslog channels */
 			if (chan->type == LOGTYPE_SYSLOG && (chan->logmask & (1 << logmsg->level))) {
 				ast_log_vsyslog(logmsg);
@@ -1234,11 +1219,20 @@ 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);
@@ -1498,31 +1492,13 @@ void ast_backtrace(void)
 #endif /* defined(HAVE_BKTR) */
 }
 
-void __ast_verbose_ap(const char *file, int line, const char *func, int level, const char *fmt, va_list ap)
+void __ast_verbose_ap(const char *file, int line, const char *func, 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;
@@ -1533,12 +1509,12 @@ void __ast_verbose_ap(const char *file, int line, const char *func, int level, c
 		now = ast_tvnow();
 		ast_localtime(&now, &tm, NULL);
 		ast_strftime(date, sizeof(date), dateformat, &tm);
-		datefmt = alloca(strlen(date) + 3 + strlen(prefix) + strlen(fmt) + 1);
-		sprintf(datefmt, "%c[%s] %s%s", (char) magic, date, prefix, fmt);
+		datefmt = alloca(strlen(date) + 3 + strlen(fmt) + 1);
+		sprintf(datefmt, "%c[%s] %s", 127, date, fmt);
 		fmt = datefmt;
 	} else {
-		char *tmp = alloca(strlen(prefix) + strlen(fmt) + 2);
-		sprintf(tmp, "%c%s%s", (char) magic, prefix, fmt);
+		char *tmp = alloca(strlen(fmt) + 2);
+		sprintf(tmp, "%c%s", 127, fmt);
 		fmt = tmp;
 	}
 
@@ -1546,19 +1522,18 @@ void __ast_verbose_ap(const char *file, int line, const char *func, int level, c
 	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, int level, const char *fmt, ...)
+void __ast_verbose(const char *file, int line, const char *func, const char *fmt, ...)
 {
 	va_list ap;
 
 	va_start(ap, fmt);
-	__ast_verbose_ap(file, line, func, level, fmt, ap);
+	__ast_verbose_ap(file, line, func, fmt, ap);
 	va_end(ap);
 }
 
@@ -1570,7 +1545,7 @@ void ast_verbose(const char *fmt, ...)
 	va_list ap;
 
 	va_start(ap, fmt);
-	__ast_verbose_ap("", 0, "", 0, fmt, ap);
+	__ast_verbose_ap("", 0, "", fmt, ap);
 	va_end(ap);
 }
 
@@ -1617,7 +1592,7 @@ static void update_logchannels(void)
 	global_logmask = 0;
 
 	AST_RWLIST_TRAVERSE(&logchannels, cur, list) {
-		cur->logmask = make_components(cur->components, cur->lineno, &cur->verbosity);
+		cur->logmask = make_components(cur->components, cur->lineno);
 		global_logmask |= cur->logmask;
 	}