2310 - add some more tracing

I've been growing lax on white-box testing when it's one of the three
big thrusts of this whole effort. Perhaps it was because I got too
obsessed with keeping traces stable and didn't notice that stable
doesn't mean "not changing". Or perhaps it's because I still don't have
a zoomable trace browser that can parse traces from disk. Or perhaps
$trace-browser is too clunky and discourages me from using it.
Regardless, I need to make the trace useable again before I work much
more on the next few rewriting transforms.

3 files changed, 14 insertions, 4 deletions

diff --git a/011load.cc b/011load.cc
index 3e1766f9..db97f3b0 100644
--- a/011load.cc
+++ b/011load.cc
@@ -47,7 +47,9 @@ long long int slurp_recipe(istream& in) {
   if (Recipe_ordinal.find(recipe_name) == Recipe_ordinal.end()) {
     Recipe_ordinal[recipe_name] = Next_recipe_ordinal++;
   }
+  trace(9991, "load") << "--- defining " << recipe_name << end();
   if (Recipe.find(Recipe_ordinal[recipe_name]) != Recipe.end()) {
+    trace(9991, "parse") << "already exists" << end();
     if (warn_on_redefine(recipe_name))
       raise << "redefining recipe " << Recipe[Recipe_ordinal[recipe_name]].name << "\n" << end();
     Recipe.erase(Recipe_ordinal[recipe_name]);
@@ -69,6 +71,7 @@ void slurp_body(istream& in, recipe& result) {
   instruction curr;
   while (next_instruction(in, &curr)) {
     // End Rewrite Instruction(curr, recipe result)
+    trace(9992, "load") << "after rewriting: " << curr.to_string() << end();
     if (!curr.is_clear())
       result.steps.push_back(curr);
   }
@@ -110,7 +113,7 @@ bool next_instruction(istream& in, instruction* curr) {
   if (SIZE(words) == 1 && !isalnum(words.at(0).at(0)) && words.at(0).at(0) != '$') {
     curr->is_label = true;
     curr->label = words.at(0);
-    trace("parse") << "label: " << curr->label << end();
+    trace(9993, "parse") << "label: " << curr->label << end();
     if (in.eof()) {
       raise_error << "7: unbalanced '[' for recipe\n" << end();
       return false;
@@ -144,12 +147,12 @@ bool next_instruction(istream& in, instruction* curr) {
     curr->ingredients.push_back(reagent(*p));
   }
 
-  trace("parse") << "instruction: " << curr->name << end();
+  trace(9993, "parse") << "instruction: " << curr->name << end();
   for (vector<reagent>::iterator p = curr->ingredients.begin(); p != curr->ingredients.end(); ++p) {
-    trace("parse") << "  ingredient: " << p->to_string() << end();
+    trace(9993, "parse") << "  ingredient: " << p->to_string() << end();
   }
   for (vector<reagent>::iterator p = curr->products.begin(); p != curr->products.end(); ++p) {
-    trace("parse") << "  product: " << p->to_string() << end();
+    trace(9993, "parse") << "  product: " << p->to_string() << end();
   }
   if (in.eof()) {
     raise_error << "9: unbalanced '[' for recipe\n" << end();
diff --git a/020run.cc b/020run.cc
index 81d0e4ae..4cccadef 100644
--- a/020run.cc
+++ b/020run.cc
@@ -134,6 +134,8 @@ inline bool routine::completed() const {
 
 //: Step 1: load all .mu files with numeric prefixes (in order)
 :(before "End Load Recipes")
+Trace_file = "interactive";
+START_TRACING_UNTIL_END_OF_SCOPE;
 load_permanently("core.mu");
 transform_all();
 
@@ -213,6 +215,7 @@ void load_permanently(string filename) {
     return;
   }
   fin >> std::noskipws;
+  trace(9990, "load") << "=== " << filename << end();
   load(fin);
   fin.close();
   // freeze everything so it doesn't get cleared by tests
diff --git a/056recipe_header.cc b/056recipe_header.cc
index d00b0a2e..38c7b204 100644
--- a/056recipe_header.cc
+++ b/056recipe_header.cc
@@ -22,6 +22,7 @@ vector<reagent> products;
 :(before "slurp_body(in, result);" following "long long int slurp_recipe(istream& in)")
 skip_whitespace(in);
 if (in.peek() != '[') {
+  trace(9999, "parse") << "recipe has a header; parsing";
   load_recipe_header(in, result);
 }
 
@@ -31,11 +32,13 @@ void load_recipe_header(istream& in, recipe& result) {
     string s = next_word(in);
     if (s == "->") break;
     result.ingredients.push_back(reagent(s));
+    trace(9999, "parse") << "header ingredient: " << result.ingredients.back().original_string << end();
     skip_whitespace(in);
   }
   while (in.peek() != '[') {
     string s = next_word(in);
     result.products.push_back(reagent(s));
+    trace(9999, "parse") << "header product: " << result.products.back().original_string << end();
     skip_whitespace(in);
   }
 }
@@ -73,6 +76,7 @@ recipe add2 x:number, y:number -> z:number [
 void check_header_products(const recipe_ordinal r) {
   const recipe& rr = Recipe[r];
   if (rr.products.empty()) return;
+  trace("transform") << "checking reply instructions against header for " << rr.name << end();
   for (long long int i = 0; i < SIZE(rr.steps); ++i) {
     const instruction& inst = rr.steps.at(i);
     if (inst.operation != REPLY) continue;