--- a/CHANGES	Sat Dec 05 18:08:24 2015 -0500
+++ b/CHANGES	Sun Sep 04 17:14:42 2016 -0400
@@ -1,5 +1,8 @@
 release [pending]
    - Fix typo in -U usage message, noticed by Joerg.
+   - Add a -debuglog option to send an execution trace to a file.
+     Intended to be used when debugging imake templates and other
+     complex input, not for debugging tradcpp itself.
 
 release 0.5.1 (20150612)
    - Fix a stupid regression in 0.5 that causes it to not recognize a

--- a/directive.c	Sat Dec 05 18:08:24 2015 -0500
+++ b/directive.c	Sun Sep 04 17:14:42 2016 -0400
@@ -179,11 +179,14 @@
 void
 d_if(struct lineplace *lp, struct place *p2, char *line)
 {
+	bool doprint;
 	char *expr;
 	bool val;
 	struct place p3 = *p2;
 	size_t oldlen;
 
+	doprint = ifstate->curtrue;
+
 	expr = macroexpand(p2, line, strlen(line), true);
 
 	oldlen = strlen(expr);
@@ -198,30 +201,54 @@
 	}
 	ifstate_push(&lp->current, val);
 	dostrfree(expr);
+
+	if (doprint) {
+		debuglog(&lp->current, "#if: %s",
+			  ifstate->curtrue ? "taken" : "not taken");
+	}
 }
 
 static
 void
 d_ifdef(struct lineplace *lp, struct place *p2, char *line)
 {
+	bool doprint;
+
+	doprint = ifstate->curtrue;
+
 	uncomment(line);
 	oneword("#ifdef", p2, line);
 	ifstate_push(&lp->current, macro_isdefined(line));
+
+	if (doprint) {
+		debuglog(&lp->current, "#ifdef %s: %s",
+			 line, ifstate->curtrue ? "taken" : "not taken");
+	}
 }
 
 static
 void
 d_ifndef(struct lineplace *lp, struct place *p2, char *line)
 {
+	bool doprint;
+
+	doprint = ifstate->curtrue;
+
 	uncomment(line);
 	oneword("#ifndef", p2, line);
 	ifstate_push(&lp->current, !macro_isdefined(line));
+
+	if (doprint) {
+		debuglog(&lp->current, "#ifndef %s: %s",
+			 line, ifstate->curtrue ? "taken" : "not taken");
+	}
 }
 
 static
 void
 d_elif(struct lineplace *lp, struct place *p2, char *line)
 {
+	bool doprint;
 	char *expr;
 	struct place p3 = *p2;
 	size_t oldlen;
@@ -231,6 +258,8 @@
 		complain_fail();
 	}
 
+	doprint = ifstate->curtrue;
+
 	if (ifstate->evertrue) {
 		ifstate->curtrue = false;
 	} else {
@@ -245,12 +274,19 @@
 		ifstate->evertrue = ifstate->curtrue;
 		dostrfree(expr);
 	}
+
+	if (doprint) {
+		debuglog2(&lp->current, &ifstate->startplace, "#elif: %s",
+			  ifstate->curtrue ? "taken" : "not taken");
+	}
 }
 
 static
 void
 d_else(struct lineplace *lp, struct place *p2, char *line)
 {
+	bool doprint;
+
 	(void)p2;
 	(void)line;
 
@@ -260,9 +296,16 @@
 		complain_fail();
 	}
 
+	doprint = ifstate->curtrue;
+
 	ifstate->curtrue = !ifstate->evertrue;
 	ifstate->evertrue = true;
 	ifstate->seenelse = true;
+
+	if (doprint) {
+		debuglog2(&lp->current, &ifstate->startplace, "#else: %s",
+			  ifstate->curtrue ? "taken" : "not taken");
+	}
 }
 
 static
@@ -276,6 +319,7 @@
 		complain(&lp->current, "Unmatched #endif");
 		complain_fail();
 	} else {
+		debuglog2(&lp->current, &ifstate->startplace, "#endif");
 		ifstate_pop();
 	}
 }
@@ -340,10 +384,12 @@
 	p4.column += pos;
 
 	if (argpos) {
+		debuglog(&lp->current, "Defining %s()", line);
 		macro_define_params(p2, line, &p3,
 				    line + argpos, &p4,
 				    line + pos);
 	} else {
+		debuglog(&lp->current, "Defining %s", line);
 		macro_define_plain(p2, line, &p4, line + pos);
 	}
 }
@@ -356,6 +402,7 @@
 
 	uncomment(line);
 	oneword("#undef", p2, line);
+	debuglog(&lp->current, "Undef %s", line);
 	macro_undef(line);
 }
 
@@ -371,13 +418,17 @@
 	len = strlen(line);
 	if (len > 2 && line[0] == '"' && line[len-1] == '"') {
 		line[len-1] = '\0';
+		debuglog(p, "Entering include file \"%s\"", line+1);
 		file_readquote(p, line+1);
+		debuglog(p, "Leaving include file \"%s\"", line+1);
 		line[len-1] = '"';
 		return true;
 	}
 	if (len > 2 && line[0] == '<' && line[len-1] == '>') {
 		line[len-1] = '\0';
+		debuglog(p, "Entering include file <%s>", line+1);
 		file_readbracket(p, line+1);
+		debuglog(p, "Leaving include file <%s>", line+1);
 		line[len-1] = '>';
 		return true;
 	}

--- a/eval.c	Sat Dec 05 18:08:24 2015 -0500
+++ b/eval.c	Sun Sep 04 17:14:42 2016 -0400
@@ -642,6 +642,7 @@
 			complain_fail();
 		}
 	}
+	debuglog(p, "Undefined symbol %s; substituting 0", word);
 	return 0;
 }
 
@@ -744,6 +745,7 @@
 #ifdef DEBUG
 	fprintf(stderr, "eval: %s\n", expr);
 #endif
+	debuglog(p, "eval: %s", expr);
 
 	tokenarray_init(&tokens);
 	tokenize(p, expr);

--- a/files.c	Sat Dec 05 18:08:24 2015 -0500
+++ b/files.c	Sun Sep 04 17:14:42 2016 -0400
@@ -182,6 +182,12 @@
 	place_setfilestart(&places.current, pf);
 	places.nextline = places.current;
 
+	if (name) {
+		debuglog(&places.current, "Reading file %s", name);
+	} else {
+		debuglog(&places.current, "Reading standard input");
+	}
+
 	bufmax = 128;
 	bufend = 0;
 	linestart = 0;

--- a/macro.c	Sat Dec 05 18:08:24 2015 -0500
+++ b/macro.c	Sun Sep 04 17:14:42 2016 -0400
@@ -876,6 +876,7 @@
 expand_domacro(struct expstate *es, struct place *p)
 {
 	struct macro *m;
+	const char *name, *val;
 	char *newbuf, *newbuf2;
 
 	if (es->curmacro == NULL) {
@@ -886,8 +887,11 @@
 			expand_send(es, p, "0", 1);
 			return;
 		}
-		m = macrotable_find(stringarray_get(&es->args, 0), false);
-		expand_send(es, p, (m != NULL) ? "1" : "0", 1);
+		name = stringarray_get(&es->args, 0);
+		m = macrotable_find(name, false);
+		val = (m != NULL) ? "1" : "0";
+		debuglog(p, "defined(%s): %s", name, val); 
+		expand_send(es, p, val, 1);
 		expstate_destroyargs(es);
 		return;
 	}
@@ -896,10 +900,15 @@
 	assert(m->inuse == false);
 	m->inuse = true;
 
+	debuglog(p, "Expanding macro %s", m->name);
 	newbuf = expand_substitute(p, es);
+	debuglog(p, "Substituting for %s: %s", m->name, newbuf);
+
 	newbuf2 = macroexpand(p, newbuf, strlen(newbuf), false);
 	dostrfree(newbuf);
 	expstate_destroyargs(es);
+	debuglog(p, "Complete expansion for %s: %s", m->name, newbuf2);
+
 	doexpand(es, p, newbuf2, strlen(newbuf2));
 	dostrfree(newbuf2);
 

--- a/main.c	Sat Dec 05 18:08:24 2015 -0500
+++ b/main.c	Sun Sep 04 17:14:42 2016 -0400
@@ -829,6 +829,7 @@
 	{ "MF",          commandline_setdependoutput },
 	{ "MQ",          commandline_setdependtarget_quoted },
 	{ "MT",          commandline_setdependtarget },
+	{ "debuglog",    debuglog_open },
 	{ "idirafter",   commandline_addincpath_late },
 	{ "imacros",     commandline_addfile_nooutput },
 	{ "include",     commandline_addfile_output },
@@ -1014,6 +1015,7 @@
 	commandline_files_cleanup();
 	commandline_macros_cleanup();
 	incpath_cleanup();
+	debuglog_close();
 
 	num = stringarray_num(&freestrings);
 	for (i=0; i<num; i++) {

--- a/place.c	Sat Dec 05 18:08:24 2015 -0500
+++ b/place.c	Sun Sep 04 17:14:42 2016 -0400
@@ -32,6 +32,7 @@
 #include <stdio.h>
 #include <stdlib.h>
 #include <string.h>
+#include <errno.h>
 
 #include "utils.h"
 #include "array.h"
@@ -52,6 +53,8 @@
 
 static const char *myprogname;
 
+static FILE *debuglogfile;
+
 ////////////////////////////////////////////////////////////
 // placefiles
 
@@ -284,6 +287,70 @@
 }
 
 ////////////////////////////////////////////////////////////
+// debug logging
+
+void
+debuglog_open(const struct place *p, /*const*/ char *file)
+{
+	assert(debuglogfile == NULL);
+	debuglogfile = fopen(file, "w");
+	if (debuglogfile == NULL) {
+		complain(p, "%s: %s", file, strerror(errno));
+		die();
+	}
+}
+
+void
+debuglog_close(void)
+{
+	if (debuglogfile != NULL) {
+		fclose(debuglogfile);
+		debuglogfile = NULL;
+	}
+}
+
+PF(2, 3) void
+debuglog(const struct place *p, const char *fmt, ...)
+{
+	va_list ap;
+
+	if (debuglogfile == NULL) {
+		return;
+	}
+
+	fprintf(debuglogfile, "%s:%u: ", place_getname(p), p->line);
+	va_start(ap, fmt);
+	vfprintf(debuglogfile, fmt, ap);
+	va_end(ap);
+	fprintf(debuglogfile, "\n");
+	fflush(debuglogfile);
+}
+
+PF(3, 4) void
+debuglog2(const struct place *p, const struct place *p2, const char *fmt, ...)
+{
+	va_list ap;
+
+	if (debuglogfile == NULL) {
+		return;
+	}
+
+	fprintf(debuglogfile, "%s:%u: ", place_getname(p), p->line);
+	if (place_samefile(p, p2)) {
+		fprintf(debuglogfile, "(block began at line %u) ",
+			p2->line);
+	} else {
+		fprintf(debuglogfile, "(block began at %s:%u)",
+			place_getname(p2), p2->line);
+	}
+	va_start(ap, fmt);
+	vfprintf(debuglogfile, fmt, ap);
+	va_end(ap);
+	fprintf(debuglogfile, "\n");
+	fflush(debuglogfile);
+}
+
+////////////////////////////////////////////////////////////
 // module init and cleanup
 
 void

--- a/tradcpp.1	Sat Dec 05 18:08:24 2015 -0500
+++ b/tradcpp.1	Sun Sep 04 17:14:42 2016 -0400
@@ -260,6 +260,14 @@
 .El
 .Ss Diagnostic Options
 .Bl -tag -width bubblebabble
+.It Fl debuglog Ar file
+Write a trace of actions and operations to
+.Ar file
+as the input is processed.
+Meant for debugging problems in complex substitution schemes fed to
+.Nm ,
+such as those used by
+.Xr imake 1 .
 .It Fl dD
 Dump all macro definitions, except for the predefined macros, after
 the normal preprocessing output.

--- a/utils.h	Sat Dec 05 18:08:24 2015 -0500
+++ b/utils.h	Sun Sep 04 17:14:42 2016 -0400
@@ -63,10 +63,16 @@
 
 /* in place.c */
 void complain_init(const char *progname);
-void complain(const struct place *, const char *fmt, ...) PF(2, 3);
+PF(2, 3) void complain(const struct place *, const char *fmt, ...);
 void complain_fail(void);
 bool complain_failed(void);
 
+void debuglog_open(const struct place *p, /*const*/ char *file);
+void debuglog_close(void);
+PF(2, 3) void debuglog(const struct place *p, const char *fmt, ...);
+PF(3, 4) void debuglog2(const struct place *p, const struct place *p2,
+			const char *fmt, ...);
+
 /* in main.c */
 void freestringlater(char *s);
 DEAD void die(void);