===================================================================
RCS file: /cvsrepo/anoncvs/cvs/src/usr.bin/tmux/format.c,v
retrieving revision 1.178
retrieving revision 1.179
diff -u -r1.178 -r1.179
--- src/usr.bin/tmux/format.c	2019/03/14 23:34:41	1.178
+++ src/usr.bin/tmux/format.c	2019/03/15 10:04:13	1.179
@@ -1,4 +1,4 @@
-/* $OpenBSD: format.c,v 1.178 2019/03/14 23:34:41 nicm Exp $ */
+/* $OpenBSD: format.c,v 1.179 2019/03/15 10:04:13 nicm Exp $ */
 
 /*
  * Copyright (c) 2011 Nicholas Marriott <nicholas.marriott@gmail.com>
@@ -208,6 +208,36 @@
 	NULL		/* z */
 };
 
+/* Is logging enabled? */
+static inline int
+format_logging(struct format_tree *ft)
+{
+	return (log_get_level() != 0 || (ft->flags & FORMAT_VERBOSE));
+}
+
+/* Log a message if verbose. */
+static void printflike(3, 4)
+format_log1(struct format_tree *ft, const char *from, const char *fmt, ...)
+{
+	va_list			 ap;
+	char			*s;
+	static const char	 spaces[] = "          ";
+
+	if (!format_logging(ft))
+		return;
+
+	va_start(ap, fmt);
+	vasprintf(&s, fmt, ap);
+	va_end(ap);
+
+	log_debug("%s: %s", from, s);
+	if (ft->item != NULL)
+		cmdq_print(ft->item, "#%.*s%s", ft->loop, spaces, s);
+
+	free(s);
+}
+#define format_log(ft, fmt, ...) format_log1(ft, __func__, fmt, ##__VA_ARGS__)
+
 /* Format job update callback. */
 static void
 format_job_update(struct job *job)
@@ -1153,6 +1183,7 @@
 	valuelen = 1;
 
 	RB_FOREACH(s, sessions, &sessions) {
+		format_log(ft, "session loop: $%u", s->id);
 		expanded = format_single(item, fmt, ft->c, ft->s, NULL, NULL);
 
 		valuelen += strlen(expanded);
@@ -1174,8 +1205,10 @@
 	size_t			 valuelen;
 	struct winlink		*wl;
 
-	if (ft->s == NULL)
+	if (ft->s == NULL) {
+		format_log(ft, "window loop but no session");
 		return (NULL);
+	}
 
 	if (format_choose(ft, fmt, &all, &active, 0) != 0) {
 		all = xstrdup(fmt);
@@ -1186,6 +1219,7 @@
 	valuelen = 1;
 
 	RB_FOREACH(wl, winlinks, &ft->s->windows) {
+		format_log(ft, "window loop: %u @%u", wl->idx, wl->window->id);
 		if (active != NULL && wl == ft->s->curw)
 			use = active;
 		else
@@ -1214,8 +1248,10 @@
 	size_t			 valuelen;
 	struct window_pane	*wp;
 
-	if (ft->w == NULL)
+	if (ft->w == NULL) {
+		format_log(ft, "pane loop but no window");
 		return (NULL);
+	}
 
 	if (format_choose(ft, fmt, &all, &active, 0) != 0) {
 		all = xstrdup(fmt);
@@ -1226,6 +1262,7 @@
 	valuelen = 1;
 
 	TAILQ_FOREACH(wp, &ft->w->panes, entry) {
+		format_log(ft, "pane loop: %%%u", wp->id);
 		if (active != NULL && wp == ft->w->active)
 			use = active;
 		else
@@ -1254,25 +1291,27 @@
 	const char		*errptr, *copy, *cp;
 	char			*copy0, *condition, *found, *new;
 	char			*value, *left, *right;
-	char			 tmp[64];
 	size_t			 valuelen;
 	int			 modifiers = 0, limit = 0;
 	struct format_modifier  *list, *fm, *cmp = NULL, *search = NULL;
 	struct format_modifier  *sub = NULL;
 	u_int			 i, count;
+	int			 j;
 
 	/* Make a copy of the key. */
 	copy = copy0 = xstrndup(key, keylen);
-	log_debug("%s: format = '%s'", __func__, copy);
 
 	/* Process modifier list. */
 	list = format_build_modifiers(ft, &copy, &count);
 	for (i = 0; i < count; i++) {
-		xsnprintf(tmp, sizeof tmp, "%s: modifier %u", __func__, i);
-		log_debug("%s = %s", tmp, list[i].modifier);
-		cmd_log_argv(list[i].argc, list[i].argv, tmp);
-
 		fm = &list[i];
+		if (format_logging(ft)) {
+			format_log(ft, "modifier %u is %s", i, fm->modifier);
+			for (j = 0; j < fm->argc; j++) {
+				format_log(ft, "modifier %u argument %d: %s", i,
+				    j, fm->argv[j]);
+			}
+		}
 		if (fm->size == 1) {
 			switch (fm->modifier[0]) {
 			case 'm':
@@ -1355,14 +1394,22 @@
 			goto fail;
 	} else if (search != NULL) {
 		/* Search in pane. */
-		if (wp == NULL)
+		if (wp == NULL) {
+			format_log(ft, "search '%s' but no pane", copy);
 			value = xstrdup("0");
-		else
+		} else {
+			format_log(ft, "search '%s' pane %%%u", copy,  wp->id);
 			xasprintf(&value, "%u", window_pane_search(wp, copy));
+		}
 	} else if (cmp != NULL) {
 		/* Comparison of left and right. */
-		if (format_choose(ft, copy, &left, &right, 1) != 0)
+		if (format_choose(ft, copy, &left, &right, 1) != 0) {
+			format_log(ft, "compare %s syntax error: %s",
+			    cmp->modifier, copy);
 			goto fail;
+		}
+		format_log(ft, "compare %s left is: %s", cmp->modifier, left);
+		format_log(ft, "compare %s right is: %s", cmp->modifier, right);
 
 		if (strcmp(cmp->modifier, "||") == 0) {
 			if (format_true(left) || format_true(right))
@@ -1397,9 +1444,12 @@
 	} else if (*copy == '?') {
 		/* Conditional: check first and choose second or third. */
 		cp = format_skip(copy + 1, ",");
-		if (cp == NULL)
+		if (cp == NULL) {
+			format_log(ft, "condition syntax error: %s", copy + 1);
 			goto fail;
+		}
 		condition = xstrndup(copy + 1, cp - (copy + 1));
+		format_log(ft, "condition is: %s", condition);
 
 		found = format_find(ft, condition, modifiers);
 		if (found == NULL) {
@@ -1412,27 +1462,42 @@
 			if (strcmp(found, condition) == 0) {
 				free(found);
 				found = xstrdup("");
+				format_log(ft, "condition '%s' found: %s",
+				    condition, found);
+			} else {
+				format_log(ft,
+				    "condition '%s' not found; assuming false",
+				    condition);
 			}
-		}
-		free(condition);
+		} else
+			format_log(ft, "condition '%s' found", condition);
 
 		if (format_choose(ft, cp + 1, &left, &right, 0) != 0) {
+			format_log(ft, "condition '%s' syntax error: %s",
+			    condition, cp + 1);
 			free(found);
 			goto fail;
 		}
-		if (format_true(found))
+		if (format_true(found)) {
+			format_log(ft, "condition '%s' is true", condition);
 			value = format_expand(ft, left);
-		else
+		} else {
+			format_log(ft, "condition '%s' is false", condition);
 			value = format_expand(ft, right);
+		}
 		free(right);
 		free(left);
 
+		free(condition);
 		free(found);
 	} else {
 		/* Neither: look up directly. */
 		value = format_find(ft, copy, modifiers);
-		if (value == NULL)
+		if (value == NULL) {
+			format_log(ft, "format '%s' not found", copy);
 			value = xstrdup("");
+		} else
+			format_log(ft, "format '%s' found: %s", copy, value);
 	}
 
 done:
@@ -1451,6 +1516,8 @@
 	/* Perform substitution if any. */
 	if (sub != NULL) {
 		new = format_substitute(value, sub->argv[0], sub->argv[1]);
+		format_log(ft, "substituted '%s' to '%s: %s", sub->argv[0],
+		    sub->argv[1], new);
 		free(value);
 		value = new;
 	}
@@ -1458,16 +1525,17 @@
 	/* Truncate the value if needed. */
 	if (limit > 0) {
 		new = utf8_trimcstr(value, limit);
+		format_log(ft, "applied length limit %d: %s", limit, new);
 		free(value);
 		value = new;
 	} else if (limit < 0) {
 		new = utf8_rtrimcstr(value, -limit);
+		format_log(ft, "applied length limit %d: %s", limit, new);
 		free(value);
 		value = new;
 	}
 
 	/* Expand the buffer and copy in the value. */
-	log_debug("%s: '%s' -> '%s'", __func__, copy0, value);
 	valuelen = strlen(value);
 	while (*len - *off < valuelen + 1) {
 		*buf = xreallocarray(*buf, 2, *len);
@@ -1476,50 +1544,51 @@
 	memcpy(*buf + *off, value, valuelen);
 	*off += valuelen;
 
+	format_log(ft, "replaced '%s' with '%s'", copy0, value);
 	free(value);
+
 	format_free_modifiers(list, count);
 	free(copy0);
 	return (0);
 
 fail:
+	format_log(ft, "failed %s", copy0);
 	format_free_modifiers(list, count);
 	free(copy0);
 	return (-1);
 }
 
-/* Expand keys in a template, passing through strftime first. */
-char *
-format_expand_time(struct format_tree *ft, const char *fmt)
-{
-	struct tm	*tm;
-	char		 s[2048];
-
-	if (fmt == NULL || *fmt == '\0')
-		return (xstrdup(""));
-
-	tm = localtime(&ft->time);
-	if (strftime(s, sizeof s, fmt, tm) == 0)
-		return (xstrdup(""));
-
-	return (format_expand(ft, s));
-}
-
 /* Expand keys in a template. */
-char *
-format_expand(struct format_tree *ft, const char *fmt)
+static char *
+format_expand1(struct format_tree *ft, const char *fmt, int time)
 {
 	char		*buf, *out, *name;
-	const char	*ptr, *s, *saved = fmt;
+	const char	*ptr, *s;
 	size_t		 off, len, n, outlen;
 	int     	 ch, brackets;
+	struct tm	*tm;
+	char		 expanded[8192];
 
-	if (fmt == NULL)
+	if (fmt == NULL || *fmt == '\0')
 		return (xstrdup(""));
 
 	if (ft->loop == FORMAT_LOOP_LIMIT)
 		return (xstrdup(""));
 	ft->loop++;
 
+	format_log(ft, "expanding format: %s", fmt);
+
+	if (time) {
+		tm = localtime(&ft->time);
+		if (strftime(expanded, sizeof expanded, fmt, tm) == 0) {
+			format_log(ft, "format is too long");
+			return (xstrdup(""));
+		}
+		if (format_logging(ft) && strcmp(expanded, fmt) != 0)
+			format_log(ft, "after time expanded: %s", expanded);
+		fmt = expanded;
+	}
+
 	len = 64;
 	buf = xmalloc(len);
 	off = 0;
@@ -1535,7 +1604,7 @@
 		}
 		fmt++;
 
-		ch = (u_char) *fmt++;
+		ch = (u_char)*fmt++;
 		switch (ch) {
 		case '(':
 			brackets = 1;
@@ -1549,15 +1618,19 @@
 				break;
 			n = ptr - fmt;
 
-			if (ft->flags & FORMAT_NOJOBS)
+			name = xstrndup(fmt, n);
+			format_log(ft, "found #(): %s", name);
+
+			if (ft->flags & FORMAT_NOJOBS) {
 				out = xstrdup("");
-			else {
-				name = xstrndup(fmt, n);
+				format_log(ft, "#() is disabled");
+			} else {
 				out = format_job_get(ft, name);
-				free(name);
+				format_log(ft, "#() result: %s", out);
 			}
-			outlen = strlen(out);
+			free(name);
 
+			outlen = strlen(out);
 			while (len - off < outlen + 1) {
 				buf = xreallocarray(buf, 2, len);
 				len *= 2;
@@ -1575,6 +1648,7 @@
 				break;
 			n = ptr - fmt;
 
+			format_log(ft, "found #{}: %.*s", (int)n, fmt);
 			if (format_replace(ft, fmt, n, &buf, &len, &off) != 0)
 				break;
 			fmt += n + 1;
@@ -1582,6 +1656,7 @@
 		case '}':
 		case '#':
 		case ',':
+			format_log(ft, "found #%c", ch);
 			while (len - off < 2) {
 				buf = xreallocarray(buf, 2, len);
 				len *= 2;
@@ -1604,6 +1679,7 @@
 				continue;
 			}
 			n = strlen(s);
+			format_log(ft, "found #%c: %s", ch, s);
 			if (format_replace(ft, s, n, &buf, &len, &off) != 0)
 				break;
 			continue;
@@ -1613,10 +1689,24 @@
 	}
 	buf[off] = '\0';
 
-	log_debug("%s: '%s' -> '%s'", __func__, saved, buf);
-
+	format_log(ft, "result is: %s", buf);
 	ft->loop--;
+
 	return (buf);
+}
+
+/* Expand keys in a template, passing through strftime first. */
+char *
+format_expand_time(struct format_tree *ft, const char *fmt)
+{
+	return (format_expand1(ft, fmt, 1));
+}
+
+/* Expand keys in a template. */
+char *
+format_expand(struct format_tree *ft, const char *fmt)
+{
+	return (format_expand1(ft, fmt, 0));
 }
 
 /* Expand a single string. */