1417 - draft zoom levels in traces

13 files changed, 83 insertions, 43 deletions

diff --git a/003trace.cc b/003trace.cc
index 5fd156b3..76f3207f 100644
--- a/003trace.cc
+++ b/003trace.cc
@@ -88,9 +88,11 @@ Hide_warnings = false;
 
 :(before "End Types")
 struct trace_line {
+  int depth;  // optional field just to help browse traces later
   string label;
   string contents;
-  trace_line(string l, string c) :label(l), contents(c) {}
+  trace_line(string l, string c) :depth(0), label(l), contents(c) {}
+  trace_line(int d, string l, string c) :depth(d), label(l), contents(c) {}
 };
 
 :(before "End Tracing")
@@ -99,14 +101,20 @@ struct trace_stream {
   // accumulator for current line
   ostringstream* curr_stream;
   string curr_layer;
+  int curr_depth;
   string dump_layer;
-  trace_stream() :curr_stream(NULL) {}
+  trace_stream() :curr_stream(NULL), curr_depth(0) {}
   ~trace_stream() { if (curr_stream) delete curr_stream; }
 
   ostringstream& stream(string layer) {
+    return stream(0, layer);
+  }
+
+  ostringstream& stream(int depth, string layer) {
     newline();
     curr_stream = new ostringstream;
     curr_layer = layer;
+    curr_depth = depth;
     return *curr_stream;
   }
 
@@ -114,13 +122,15 @@ struct trace_stream {
   void newline() {
     if (!curr_stream) return;
     string curr_contents = curr_stream->str();
-    past_lines.push_back(trace_line(trim(curr_layer), curr_contents));  // preserve indent in contents
+    past_lines.push_back(trace_line(curr_depth, trim(curr_layer), curr_contents));  // preserve indent in contents
     if (curr_layer == dump_layer || curr_layer == "dump" || dump_layer == "all" ||
         (!Hide_warnings && curr_layer == "warn"))
 //?     if (dump_layer == "all" && (Current_routine->id == 3 || curr_layer == "schedule")) //? 1
       cerr << curr_layer << ": " << curr_contents << '\n';
     delete curr_stream;
     curr_stream = NULL;
+    curr_layer.clear();
+    curr_depth = 0;
   }
 
   // Useful for debugging.
@@ -130,6 +140,8 @@ struct trace_stream {
     layer = trim(layer);
     for (vector<trace_line>::iterator p = past_lines.begin(); p != past_lines.end(); ++p)
       if (layer.empty() || layer == p->label) {
+        if (p->depth)
+          output << std::setw(4) << p->depth << ' ';
         output << p->label << ": " << p->contents << '\n';
       }
     return output.str();
@@ -141,7 +153,7 @@ struct trace_stream {
 trace_stream* Trace_stream = NULL;
 
 // Top-level helper. IMPORTANT: can't nest.
-#define trace(layer)  !Trace_stream ? cerr /*print nothing*/ : Trace_stream->stream(layer)
+#define trace(...)  !Trace_stream ? cerr /*print nothing*/ : Trace_stream->stream(__VA_ARGS__)
 // Warnings should go straight to cerr by default since calls to trace() have
 // some unfriendly constraints (they delay printing, they can't nest)
 #define raise  ((!Trace_stream || !Hide_warnings) ? cerr /*do print*/ : Trace_stream->stream("warn"))
@@ -338,3 +350,24 @@ using std::ifstream;
 using std::ofstream;
 
 #define unused  __attribute__((unused))
+
+:(before "End Globals")
+//: In future layers we'll use the depth field as follows:
+//:
+//: Mu 'applications' will be able to use depths 1-99 as they like.
+//: Depth 100 will be for scheduling (more on that later).
+const int Scheduling_depth = 100;
+//: Primitive statements will occupy 101-9998
+const int Initial_callstack_depth = 101;
+const int Max_callstack_depth = 9998;
+//: (ignore this until the call layer)
+:(before "End Globals")
+int Callstack_depth = 0;
+:(before "End Setup")
+Callstack_depth = 0;
+//: Finally, details of primitive mu statements will occupy depth 9999 (more on that later as well)
+:(before "End Globals")
+const int Primitive_recipe_depth = 9999;
+//:
+//: This framework should help us hide some details at each level, mixing
+//: static ideas like layers with the dynamic notion of call-stack depth.
diff --git a/020run.cc b/020run.cc
index 4c3cc548..07a02229 100644
--- a/020run.cc
+++ b/020run.cc
@@ -58,21 +58,18 @@ void run_current_routine()
   {
     // Running One Instruction.
     if (current_instruction().is_label) { ++current_step_index(); continue; }
-//?     trace("run") << "instruction " << current_recipe_name() << '/' << current_step_index();
-    trace("run") << current_instruction().to_string();
+    trace(Initial_callstack_depth+Callstack_depth, "run") << current_instruction().to_string();
     assert(Memory[0] == 0);
     // Read all ingredients from memory.
     // Each ingredient loads a vector of values rather than a single value; mu
     // permits operating on reagents spanning multiple locations.
     vector<vector<double> > ingredients;
     for (long long int i = 0; i < SIZE(current_instruction().ingredients); ++i) {
-//?       trace("run") << "ingredient " << i << " is " << current_instruction().ingredients.at(i).name;
       ingredients.push_back(read_memory(current_instruction().ingredients.at(i)));
     }
     // Instructions below will write to 'products' or to 'instruction_counter'.
     vector<vector<double> > products;
     long long int instruction_counter = current_step_index();
-//?     cout << "AAA: " << current_instruction().to_string() << '\n'; //? 1
     switch (current_instruction().operation) {
       // Primitive Recipe Implementations
       case COPY: {
@@ -84,17 +81,12 @@ void run_current_routine()
         cout << "not a primitive op: " << current_instruction().operation << '\n';
       }
     }
-//?     cout << "BBB: " << current_instruction().to_string() << '\n'; //? 1
     if (SIZE(products) < SIZE(current_instruction().products))
       raise << "failed to write to all products! " << current_instruction().to_string();
-//?     cout << "CCC: " << current_instruction().to_string() << '\n'; //? 1
     for (long long int i = 0; i < SIZE(current_instruction().products); ++i) {
-//?       trace("run") << "product " << i << " is " << current_instruction().products.at(i).name;
       write_memory(current_instruction().products.at(i), products.at(i));
     }
-//?     cout << "DDD: " << current_instruction().to_string() << '\n'; //? 1
     current_step_index() = instruction_counter+1;
-//?     cerr << "screen: " << Memory[SCREEN] << '\n'; //? 1
   }
   stop_running_current_routine:;
 }
@@ -186,7 +178,7 @@ vector<double> read_memory(reagent x) {
   long long int size = size_of(x);
   for (long long int offset = 0; offset < size; ++offset) {
     double val = Memory[base+offset];
-    trace("mem") << "location " << base+offset << " is " << val;
+    trace(Primitive_recipe_depth, "mem") << "location " << base+offset << " is " << val;
     result.push_back(val);
   }
   return result;
@@ -198,7 +190,7 @@ void write_memory(reagent x, vector<double> data) {
   if (size_of(x) != SIZE(data))
     raise << "size mismatch in storing to " << x.to_string() << '\n';
   for (long long int offset = 0; offset < SIZE(data); ++offset) {
-    trace("mem") << "storing " << data.at(offset) << " in location " << base+offset;
+    trace(Primitive_recipe_depth, "mem") << "storing " << data.at(offset) << " in location " << base+offset;
     Memory[base+offset] = data.at(offset);
   }
 }
diff --git a/023jump.cc b/023jump.cc
index fba76150..a737bf82 100644
--- a/023jump.cc
+++ b/023jump.cc
@@ -19,7 +19,7 @@ case JUMP: {
   assert(SIZE(ingredients) == 1);
   assert(scalar(ingredients.at(0)));
   instruction_counter += ingredients.at(0).at(0);
-  trace("run") << "jumping to instruction " << instruction_counter+1;
+  trace(Primitive_recipe_depth, "run") << "jumping to instruction " << instruction_counter+1;
   break;
 }
 
@@ -48,12 +48,12 @@ case JUMP_IF: {
   assert(SIZE(ingredients) == 2);
   assert(scalar(ingredients.at(0)));
   if (!ingredients.at(0).at(0)) {
-    trace("run") << "jump-if fell through";
+    trace(Primitive_recipe_depth, "run") << "jump-if fell through";
     break;
   }
   assert(scalar(ingredients.at(1)));
   instruction_counter += ingredients.at(1).at(0);
-  trace("run") << "jumping to instruction " << instruction_counter+1;
+  trace(Primitive_recipe_depth, "run") << "jumping to instruction " << instruction_counter+1;
   break;
 }
 
@@ -87,12 +87,12 @@ case JUMP_UNLESS: {
   assert(SIZE(ingredients) == 2);
   assert(scalar(ingredients.at(0)));
   if (ingredients.at(0).at(0)) {
-    trace("run") << "jump-unless fell through";
+    trace(Primitive_recipe_depth, "run") << "jump-unless fell through";
     break;
   }
   assert(scalar(ingredients.at(1)));
   instruction_counter += ingredients.at(1).at(0);
-  trace("run") << "jumping to instruction " << instruction_counter+1;
+  trace(Primitive_recipe_depth, "run") << "jumping to instruction " << instruction_counter+1;
   break;
 }
 
diff --git a/027debug.cc b/027debug.cc
index 6b409d0b..60830bd8 100644
--- a/027debug.cc
+++ b/027debug.cc
@@ -8,12 +8,12 @@ Recipe_number["$print"] = _PRINT;
 case _PRINT: {
   for (long long int i = 0; i < SIZE(ingredients); ++i) {
     if (isa_literal(current_instruction().ingredients.at(i))) {
-      trace("run") << "$print: " << current_instruction().ingredients.at(i).name;
+      trace(Primitive_recipe_depth, "run") << "$print: " << current_instruction().ingredients.at(i).name;
       cout << current_instruction().ingredients.at(i).name;
     }
     else {
       for (long long int j = 0; j < SIZE(ingredients.at(i)); ++j) {
-        trace("run") << "$print: " << ingredients.at(i).at(j);
+        trace(Primitive_recipe_depth, "run") << "$print: " << ingredients.at(i).at(j);
         if (j > 0) cout << " ";
         cout << ingredients.at(i).at(j);
       }
diff --git a/030container.cc b/030container.cc
index 5eeee367..fbb0f87c 100644
--- a/030container.cc
+++ b/030container.cc
@@ -112,11 +112,11 @@ case GET: {
   for (long long int i = 0; i < offset; ++i) {
     src += size_of(Type[base_type].elements.at(i));
   }
-  trace("run") << "address to copy is " << src;
+  trace(Primitive_recipe_depth, "run") << "address to copy is " << src;
   assert(Type[base_type].kind == container);
   assert(SIZE(Type[base_type].elements) > offset);
   type_number src_type = Type[base_type].elements.at(offset).at(0);
-  trace("run") << "its type is " << src_type;
+  trace(Primitive_recipe_depth, "run") << "its type is " << src_type;
   reagent tmp;
   tmp.set_value(src);
   tmp.types.push_back(src_type);
@@ -160,7 +160,7 @@ case GET_ADDRESS: {
   for (long long int i = 0; i < offset; ++i) {
     result += size_of(Type[base_type].elements.at(i));
   }
-  trace("run") << "address to copy is " << result;
+  trace(Primitive_recipe_depth, "run") << "address to copy is " << result;
   products.resize(1);
   products.at(0).push_back(result);
   break;
diff --git a/031address.cc b/031address.cc
index 48034f37..cee1d0e8 100644
--- a/031address.cc
+++ b/031address.cc
@@ -44,7 +44,7 @@ reagent deref(reagent x) {
 
   // compute value
   result.set_value(Memory[x.value]);
-  trace("mem") << "location " << x.value << " is " << result.value;
+  trace(Primitive_recipe_depth, "mem") << "location " << x.value << " is " << result.value;
 
   // populate types
   copy(++x.types.begin(), x.types.end(), inserter(result.types, result.types.begin()));
diff --git a/032array.cc b/032array.cc
index 2ee3325d..deef886e 100644
--- a/032array.cc
+++ b/032array.cc
@@ -75,18 +75,18 @@ Recipe_number["index"] = INDEX;
 case INDEX: {
 //?   if (Trace_stream) Trace_stream->dump_layer = "run"; //? 1
   reagent base = canonize(current_instruction().ingredients.at(0));
-//?   trace("run") << "ingredient 0 after canonize: " << base.to_string(); //? 1
+//?   trace(Primitive_recipe_depth, "run") << "ingredient 0 after canonize: " << base.to_string(); //? 1
   long long int base_address = base.value;
   assert(base.types.at(0) == Type_number["array"]);
   reagent offset = canonize(current_instruction().ingredients.at(1));
-//?   trace("run") << "ingredient 1 after canonize: " << offset.to_string(); //? 1
+//?   trace(Primitive_recipe_depth, "run") << "ingredient 1 after canonize: " << offset.to_string(); //? 1
   vector<double> offset_val(read_memory(offset));
   vector<type_number> element_type = array_element(base.types);
-//?   trace("run") << "offset: " << offset_val.at(0); //? 1
-//?   trace("run") << "size of elements: " << size_of(element_type); //? 1
+//?   trace(Primitive_recipe_depth, "run") << "offset: " << offset_val.at(0); //? 1
+//?   trace(Primitive_recipe_depth, "run") << "size of elements: " << size_of(element_type); //? 1
   long long int src = base_address + 1 + offset_val.at(0)*size_of(element_type);
-  trace("run") << "address to copy is " << src;
-  trace("run") << "its type is " << element_type.at(0);
+  trace(Primitive_recipe_depth, "run") << "address to copy is " << src;
+  trace(Primitive_recipe_depth, "run") << "its type is " << element_type.at(0);
   reagent tmp;
   tmp.set_value(src);
   copy(element_type.begin(), element_type.end(), inserter(tmp.types, tmp.types.begin()));
diff --git a/035call.cc b/035call.cc
index b3c0ba9c..0a783b97 100644
--- a/035call.cc
+++ b/035call.cc
@@ -80,6 +80,8 @@ default: {
     raise << "undefined operation " << current_instruction().operation << ": " << current_instruction().to_string() << '\n';
     break;
   }
+  ++Callstack_depth;
+  assert(Callstack_depth < 9000);  // 9998-101 plus cushion
   Current_routine->calls.push_front(call(current_instruction().operation));
   continue;  // not done with caller; don't increment current_step_index()
 }
@@ -100,6 +102,7 @@ inline const vector<instruction>& routine::steps() const {
 // when we reach the end of one call, we may reach the end of the one below
 // it, and the one below that, and so on
 while (current_step_index() >= SIZE(Current_routine->steps())) {
+  --Callstack_depth;
   Current_routine->calls.pop_front();
   if (Current_routine->calls.empty()) return;
   // todo: no results returned warning
diff --git a/037call_reply.cc b/037call_reply.cc
index 8f05309e..4806c169 100644
--- a/037call_reply.cc
+++ b/037call_reply.cc
@@ -19,6 +19,7 @@ Recipe_number["reply"] = REPLY;
 :(before "End Primitive Recipe Implementations")
 case REPLY: {
   const instruction& reply_inst = current_instruction();  // save pointer into recipe before pop
+  --Callstack_depth;
   Current_routine->calls.pop_front();
   // just in case 'main' returns a value, drop it for now
   if (Current_routine->calls.empty()) goto stop_running_current_routine;
@@ -28,7 +29,7 @@ case REPLY: {
   // check that any reply ingredients with /same-as-ingredient connect up
   // the corresponding ingredient and product in the caller.
   for (long long int i = 0; i < SIZE(caller_instruction.products); ++i) {
-    trace("run") << "result " << i << " is " << to_string(ingredients.at(i));
+    trace(Primitive_recipe_depth, "run") << "result " << i << " is " << to_string(ingredients.at(i));
     if (has_property(reply_inst.ingredients.at(i), "same-as-ingredient")) {
       vector<string> tmp = property(reply_inst.ingredients.at(i), "same-as-ingredient");
       assert(SIZE(tmp) == 1);
diff --git a/039wait.cc b/039wait.cc
index 14a9ee18..01237863 100644
--- a/039wait.cc
+++ b/039wait.cc
@@ -40,7 +40,7 @@ case WAIT_FOR_LOCATION: {
   Current_routine->state = WAITING;
   Current_routine->waiting_on_location = loc.value;
   Current_routine->old_value_of_waiting_location = Memory[loc.value];
-  trace("run") << "waiting for location " << loc.value << " to change from " << Memory[loc.value];
+  trace(Primitive_recipe_depth, "run") << "waiting for location " << loc.value << " to change from " << Memory[loc.value];
 //?   trace("schedule") << Current_routine->id << ": waiting for location " << loc.value << " to change from " << Memory[loc.value]; //? 2
   break;
 }
@@ -99,7 +99,7 @@ case WAIT_FOR_ROUTINE: {
   Current_routine->state = WAITING;
   assert(scalar(ingredients.at(0)));
   Current_routine->waiting_on_routine = ingredients.at(0).at(0);
-  trace("run") << "waiting for routine " << ingredients.at(0).at(0);
+  trace(Primitive_recipe_depth, "run") << "waiting for routine " << ingredients.at(0).at(0);
   break;
 }
 
diff --git a/042new.cc b/042new.cc
index decb76db..d297196b 100644
--- a/042new.cc
+++ b/042new.cc
@@ -23,7 +23,7 @@ long long int alloc, alloc_max;
 alloc = Memory_allocated_until;
 Memory_allocated_until += Initial_memory_per_routine;
 alloc_max = Memory_allocated_until;
-trace("new") << "routine allocated memory from " << alloc << " to " << alloc_max;
+trace(Primitive_recipe_depth, "new") << "routine allocated memory from " << alloc << " to " << alloc_max;
 
 //:: First handle 'type' operands.
 
@@ -39,7 +39,7 @@ if (inst.operation == Recipe_number["new"]) {
   if (inst.ingredients.at(0).properties.at(0).second.at(0) == "type") {
     inst.ingredients.at(0).set_value(Type_number[inst.ingredients.at(0).name]);
   }
-  trace("new") << inst.ingredients.at(0).name << " -> " << inst.ingredients.at(0).value;
+  trace(Primitive_recipe_depth, "new") << inst.ingredients.at(0).name << " -> " << inst.ingredients.at(0).value;
 }
 
 //:: Now implement the primitive recipe.
@@ -61,7 +61,7 @@ case NEW: {
     if (SIZE(current_instruction().ingredients) > 1) {
       // array
       array_length = ingredients.at(1).at(0);
-      trace("mem") << "array size is " << array_length;
+      trace(Primitive_recipe_depth, "mem") << "array size is " << array_length;
       size = array_length*size_of(type) + /*space for length*/1;
     }
     else {
@@ -73,7 +73,7 @@ case NEW: {
   // really crappy at the moment
   ensure_space(size);
   const long long int result = Current_routine->alloc;
-  trace("mem") << "new alloc: " << result;
+  trace(Primitive_recipe_depth, "mem") << "new alloc: " << result;
   // save result
   products.resize(1);
   products.at(0).push_back(result);
@@ -100,7 +100,7 @@ void ensure_space(long long int size) {
     Current_routine->alloc = Memory_allocated_until;
     Memory_allocated_until += Initial_memory_per_routine;
     Current_routine->alloc_max = Memory_allocated_until;
-    trace("new") << "routine allocated memory from " << Current_routine->alloc << " to " << Current_routine->alloc_max;
+    trace(Primitive_recipe_depth, "new") << "routine allocated memory from " << Current_routine->alloc << " to " << Current_routine->alloc_max;
   }
 }
 
diff --git a/050scenario.cc b/050scenario.cc
index ba5aa755..1d7366cd 100644
--- a/050scenario.cc
+++ b/050scenario.cc
@@ -218,7 +218,7 @@ void check_memory(const string& s) {
     int value = 0;  in >> value;
     if (locations_checked.find(address) != locations_checked.end())
       raise << "duplicate expectation for location " << address << '\n';
-    trace("run") << "checking location " << address;
+    trace(Primitive_recipe_depth, "run") << "checking location " << address;
     if (Memory[address] != value) {
       if (Current_scenario)
         raise << "\nF - " << Current_scenario->name << ": expected location " << address << " to contain " << value << " but saw " << Memory[address] << '\n';
@@ -251,12 +251,12 @@ void check_type(const string& lhs, istream& in) {
 }
 
 void check_string(long long int address, const string& literal) {
-  trace("run") << "checking string length at " << address;
+  trace(Primitive_recipe_depth, "run") << "checking string length at " << address;
   if (Memory[address] != SIZE(literal))
     raise << "expected location " << address << " to contain length " << SIZE(literal) << " of string [" << literal << "] but saw " << Memory[address] << '\n';
   ++address;  // now skip length
   for (long long int i = 0; i < SIZE(literal); ++i) {
-    trace("run") << "checking location " << address+i;
+    trace(Primitive_recipe_depth, "run") << "checking location " << address+i;
     if (Memory[address+i] != literal.at(i))
       raise << "expected location " << (address+i) << " to contain " << literal.at(i) << " but saw " << Memory[address+i] << '\n';
   }
diff --git a/999spaces.cc b/999spaces.cc
index e7cd8509..019c767c 100644
--- a/999spaces.cc
+++ b/999spaces.cc
@@ -20,3 +20,14 @@ assert(Reserved_for_tests == 1000);
 //: 1-99 - primitives
 //: 100-999 - defined in .mu files as sequences of primitives
 //: 1000 onwards - reserved for tests, cleared between tests
+
+//:: Depths for tracing
+//:
+//: 0 - unused
+//: 1-99 - app-level trace statements in mu
+//: 100 - schedule
+//: 101-9998 - call-stack statements (mostly label run)
+assert(Initial_callstack_depth == 101);
+assert(Max_callstack_depth == 9998);
+//: 9999 - intra-instruction lines (mostly label mem)
+assert(Primitive_recipe_depth == 9999);