From c442a5ad806b6cccbb3ec4c5744b14b0c1f31a01 Mon Sep 17 00:00:00 2001 From: Kartik Agaram Date: Mon, 25 Feb 2019 00:17:46 -0800 Subject: 4987 - support `browse_trace` tool in SubX I've extracted it into a separate binary, independent of my Mu prototype. I also cleaned up my tracing layer to be a little nicer. Major improvements: - Realized that incremental tracing really ought to be the default. And to minimize printing traces to screen. - Finally figured out how to combine layers and call stack frames in a single dimension of depth. The answer: optimize for the experience of `browse_trace`. Instructions occupy a range of depths based on their call stack frame, and minor details of an instruction lie one level deeper in each case. Other than that, I spent some time adjusting levels everywhere to make `browse_trace` useful. --- 003trace.cc | 465 +++++++++++++++++-------------- 011load.cc | 16 +- 012transform.cc | 4 +- 013update_operation.cc | 2 +- 019type_abbreviations.cc | 10 +- 020run.cc | 33 ++- 021check_instruction.cc | 2 +- 024jump.cc | 10 +- 026call.cc | 24 +- 028call_return.cc | 14 +- 029tools.cc | 18 +- 030container.cc | 16 +- 031merge.cc | 6 +- 032array.cc | 14 +- 033exclusive_container.cc | 10 +- 034address.cc | 20 +- 035lookup.cc | 2 +- 036abandon.cc | 6 +- 038new_text.cc | 6 +- 040brace.cc | 16 +- 042name.cc | 8 +- 043space.cc | 2 +- 045closure_name.cc | 4 +- 046check_type_by_name.cc | 6 +- 050scenario.cc | 13 +- 052tangle.cc | 6 +- 053recipe_header.cc | 32 +-- 054static_dispatch.cc | 18 +- 055shape_shifting_container.cc | 2 +- 056shape_shifting_recipe.cc | 46 ++-- 057immutable.cc | 2 +- 060rewrite_literal_string.cc | 2 +- 062convert_ingredients_to_text.cc | 6 +- 069hash.cc | 2 +- 072recipe.cc | 10 +- 073scheduler.cc | 4 +- 074wait.cc | 20 +- 076continuation.cc | 26 +- 085scenario_console.cc | 14 +- 089scenario_filesystem.cc | 10 +- 099hardware_checks.cc | 2 +- 100trace_browser.cc | 528 ----------------------------------- 101run_sandboxed.cc | 12 +- 999spaces.cc | 10 +- Readme.md | 14 +- browse_trace/Readme.md | 78 ++++++ browse_trace/browse_trace | 7 + browse_trace/browse_trace.cc | 546 +++++++++++++++++++++++++++++++++++++ browse_trace/build | 83 ++++++ browse_trace/clean | 6 + subx/003trace.cc | 429 +++++++++++++++++------------ subx/010---vm.cc | 30 +- subx/011run.cc | 9 +- subx/012elf.cc | 13 +- subx/013direct_addressing.cc | 82 +++--- subx/014indirect_addressing.cc | 46 ++-- subx/015immediate_addressing.cc | 56 ++-- subx/016index_addressing.cc | 8 +- subx/017jump_disp8.cc | 98 +++---- subx/018jump_disp32.cc | 98 +++---- subx/019functions.cc | 15 +- subx/020syscalls.cc | 48 ++-- subx/021byte_addressing.cc | 18 +- subx/028translate.cc | 3 + subx/030---operands.cc | 2 +- subx/031check_operands.cc | 2 +- subx/032check_operand_bounds.cc | 2 +- subx/034compute_segment_address.cc | 8 +- subx/035labels.cc | 6 +- subx/036global_variables.cc | 2 +- subx/038---literal_strings.cc | 2 +- subx/039debug.cc | 2 +- subx/040---tests.cc | 4 +- subx/drun | 4 +- 74 files changed, 1764 insertions(+), 1436 deletions(-) delete mode 100644 100trace_browser.cc create mode 100644 browse_trace/Readme.md create mode 100755 browse_trace/browse_trace create mode 100644 browse_trace/browse_trace.cc create mode 100755 browse_trace/build create mode 100755 browse_trace/clean diff --git a/003trace.cc b/003trace.cc index 11b54818..3213effc 100644 --- a/003trace.cc +++ b/003trace.cc @@ -13,30 +13,31 @@ //: longer valid. In both cases you end up having to reorganize code as well as //: tests, an error-prone activity. //: -//: In response, this layer introduces the notion of *domain-driven* testing. -//: We focus on the domain of inputs the whole program needs to handle rather -//: than the correctness of individual functions. All tests invoke the program -//: in a single way: by calling run() with some input. As the program operates -//: on the input, it traces out a list of _facts_ deduced about the domain: +//: In response, this layer introduces the notion of domain-driven *white-box* +//: testing. We focus on the domain of inputs the whole program needs to +//: handle rather than the correctness of individual functions. All white-box +//: tests (we call them 'scenarios') invoke the program in a single way: by +//: calling run() with some input. As the program operates on the input, it +//: traces out a list of _facts_ deduced about the domain: //: trace("label") << "fact 1: " << val; //: -//: Tests can now check these facts: +//: Scenarios can now check these facts: //: :(scenario foo) //: 34 # call run() with this input //: +label: fact 1: 34 # 'run' should have deduced this fact //: -label: fact 1: 35 # the trace should not contain such a fact //: //: Since we never call anything but the run() function directly, we never have -//: to rewrite the tests when we reorganize the internals of the program. We +//: to rewrite the scenarios when we reorganize the internals of the program. We //: just have to make sure our rewrite deduces the same facts about the domain, //: and that's something we're going to have to do anyway. //: //: To avoid the combinatorial explosion of integration tests, each layer -//: mainly logs facts to the trace with a common *label*. All tests in a layer -//: tend to check facts with this label. Validating the facts logged with a -//: specific label is like calling functions of that layer directly. +//: mainly logs facts to the trace with a common *label*. All scenarios in a +//: layer tend to check facts with this label. Validating the facts logged +//: with a specific label is like calling functions of that layer directly. //: -//: To build robust tests, trace facts about your domain rather than details of +//: To build robust scenarios, trace facts about your domain rather than details of //: how you computed them. //: //: More details: http://akkartik.name/blog/tracing-tests @@ -44,159 +45,188 @@ //: --- //: //: Between layers and domain-driven testing, programming starts to look like a -//: fundamentally different activity. Instead of a) superficial, b) local rules -//: on c) code [like say http://blog.bbv.ch/2013/06/05/clean-code-cheat-sheet], -//: we allow programmers to engage with the a) deep, b) global structure of the -//: c) domain. If you can systematically track discontinuities in the domain, -//: you don't care if the code used gotos as long as it passed the tests. If -//: tests become more robust to run it becomes easier to try out radically -//: different implementations for the same program. If code is super-easy to -//: rewrite, it becomes less important what indentation style it uses, or that -//: the objects are appropriately encapsulated, or that the functions are -//: referentially transparent. +//: fundamentally different activity. Instead of focusing on a) superficial, +//: b) local rules on c) code [like say http://blog.bbv.ch/2013/06/05/clean-code-cheat-sheet], +//: we allow programmers to engage with the a) deep, b) global structure of +//: the c) domain. If you can systematically track discontinuities in the +//: domain, you don't care if the code used gotos as long as it passed all +//: scenarios. If scenarios become more robust to run, it becomes easier to +//: try out radically different implementations for the same program. If code +//: is super-easy to rewrite, it becomes less important what indentation style +//: it uses, or that the objects are appropriately encapsulated, or that the +//: functions are referentially transparent. //: //: Instead of plumbing, programming becomes building and gradually refining a -//: map of the environment the program must operate under. Whether a program is -//: 'correct' at a given point in time is a red herring; what matters is -//: avoiding regression by monotonically nailing down the more 'eventful' parts -//: of the terrain. It helps readers new and old, and rewards curiosity, to -//: organize large programs in self-similar hierarchies of example scenarios +//: map of the environment the program must operate under. Whether a program +//: is 'correct' at a given point in time is a red herring; what matters is +//: avoiding regression by monotonically nailing down the more 'eventful' +//: parts of the terrain. It helps readers new and old, and rewards curiosity, +//: to organize large programs in self-similar hierarchies of example scenarios //: colocated with the code that makes them work. //: //: "Programming properly should be regarded as an activity by which //: programmers form a mental model, rather than as production of a program." //: -- Peter Naur (http://alistair.cockburn.us/ASD+book+extract%3A+%22Naur,+Ehn,+Musashi%22) -:(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) :depth(0), label(l), contents(c) {} - trace_line(int d, string l, string c) :depth(d), label(l), contents(c) {} -}; +//:: == Core data structures -//: Support for tracing an entire run. -//: Traces can have a lot of overhead, so only turn them on when asked. -:(before "End Commandline Options(*arg)") -else if (is_equal(*arg, "--trace")) { - Save_trace = true; -} -:(before "End Commandline Parsing") -if (Save_trace) { - cerr << "initializing trace\n"; - Trace_stream = new trace_stream; -} -:(code) -void cleanup_main() { - if (!Trace_stream) return; - if (Save_trace) - Trace_stream->save(); - delete Trace_stream; - Trace_stream = NULL; -} -:(before "End One-time Setup") -atexit(cleanup_main); +:(before "End Globals") +trace_stream* Trace_stream = NULL; :(before "End Types") -// Pre-define some global constants that trace_stream needs to know about. -// Since they're in the Types section, they'll be included in any cleaved -// compilation units. So no extern linkage. -const int Max_depth = 9999; -const int Error_depth = 0; // definitely always print errors -const int App_depth = 2; // temporarily where all Mu code will trace to - struct trace_stream { vector past_lines; - // accumulator for current line - ostringstream* curr_stream; - string curr_label; - int curr_depth; - int callstack_depth; - int collect_depth; - ofstream null_stream; // never opens a file, so writes silently fail - trace_stream() :curr_stream(NULL), curr_depth(Max_depth), callstack_depth(0), collect_depth(Max_depth) {} - ~trace_stream() { if (curr_stream) delete curr_stream; } - - ostream& stream(string label) { - return stream(Max_depth, label); - } + // End trace_stream Fields - ostream& stream(int depth, string label) { - if (depth > collect_depth) return null_stream; - curr_stream = new ostringstream; - curr_label = label; - curr_depth = depth; - return *curr_stream; + trace_stream() { + // End trace_stream Constructor } - - void save() { - cerr << "saving trace to 'last_run'\n"; - ofstream fout("last_run"); - fout << readable_contents(""); - fout.close(); + ~trace_stream() { + // End trace_stream Destructor } + // End trace_stream Methods +}; - // be sure to call this before messing with curr_stream or curr_label - void newline(); - // useful for debugging - string readable_contents(string label); // empty label = show everything +//:: == Adding to the trace + +//: Top-level method is trace() which can be used like an ostream. Usage: +//: trace(depth, label) << ... << end(); +//: Don't forget the 'end()' to actually append to the trace. +:(before "End Includes") +// No brackets around the expansion so that it prints nothing if Trace_stream +// isn't initialized. +#define trace(...) !Trace_stream ? cerr : Trace_stream->stream(__VA_ARGS__) + +:(before "End trace_stream Fields") +// accumulator for current trace_line +ostringstream* curr_stream; +string curr_label; +int curr_depth; +// other stuff +int collect_depth; // avoid tracing lower levels for speed +ofstream null_stream; // never opened, so writes to it silently fail + +//: Some constants. +:(before "struct trace_stream") // include constants in all cleaved compilation units +const int Max_depth = 9999; +// Most important traces are printed to the screen by default +const int Error_depth = 0; +:(before "End Globals") +int Hide_errors = false; // if set, don't print errors to screen +:(before "End trace_stream Constructor") +curr_stream = NULL; +curr_depth = Max_depth; +collect_depth = Max_depth; +:(before "End Reset") +Hide_errors = false; + +:(before "struct trace_stream") +struct trace_line { + string contents; + string label; + int depth; // 0 is 'sea level'; positive integers are progressively 'deeper' and lower level + trace_line(string c, string l) { + contents = c; + label = l; + depth = 0; + } + trace_line(string c, string l, int d) { + contents = c; + label = l; + depth = d; + } }; +//: Starting a new trace line. +:(before "End trace_stream Methods") +ostream& stream(string label) { + return stream(Max_depth, label); +} + +ostream& stream(int depth, string label) { + if (depth > collect_depth) return null_stream; + curr_stream = new ostringstream; + curr_label = label; + curr_depth = depth; + return *curr_stream; +} + +//: End of a trace line; append it to the trace. +:(before "End Types") +struct end {}; +:(code) +ostream& operator<<(ostream& os, end /*unused*/) { + if (Trace_stream) Trace_stream->newline(); + return os; +} + +:(before "End trace_stream Methods") +void newline(); :(code) void trace_stream::newline() { if (!curr_stream) return; string curr_contents = curr_stream->str(); if (!curr_contents.empty()) { - past_lines.push_back(trace_line(curr_depth, trim(curr_label), curr_contents)); // preserve indent in contents - if ((!Hide_errors && curr_label == "error") - || Dump_trace - || (!Dump_label.empty() && curr_label == Dump_label)) - cerr << curr_label << ": " << curr_contents << '\n'; + past_lines.push_back(trace_line(curr_contents, trim(curr_label), curr_depth)); // preserve indent in contents + // maybe incrementally dump trace + trace_line& t = past_lines.back(); + if (!Hide_errors && curr_depth == Error_depth) { + cerr << std::setw(4) << t.depth << ' ' << t.label << ": " << t.contents << '\n'; + } + // End trace Commit } + + // clean up delete curr_stream; curr_stream = NULL; curr_label.clear(); curr_depth = Max_depth; } -string trace_stream::readable_contents(string label) { - ostringstream output; - label = trim(label); - for (vector::iterator p = past_lines.begin(); p != past_lines.end(); ++p) - if (label.empty() || label == p->label) - output << std::setw(4) << p->depth << ' ' << p->label << ": " << p->contents << '\n'; - return output.str(); -} +//:: == Initializing the trace in scenarios -:(before "End Globals") -trace_stream* Trace_stream = NULL; -int Trace_errors = 0; // used only when Trace_stream is NULL +:(before "End Includes") +#define START_TRACING_UNTIL_END_OF_SCOPE lease_tracer leased_tracer; +:(before "End Test Setup") +START_TRACING_UNTIL_END_OF_SCOPE -:(before "End Globals") -bool Hide_errors = false; // if set, don't print even error trace lines to screen -bool Dump_trace = false; // if set, print trace lines to screen -string Dump_label = ""; // if set, print trace lines matching a single label to screen -:(before "End Reset") -Hide_errors = false; -Dump_trace = false; // toggle this to print traces to screen as they are emitted -Dump_label = ""; +//: Trace_stream is a resource, lease_tracer uses RAII to manage it. +:(before "End Types") +struct lease_tracer { + lease_tracer(); + ~lease_tracer(); +}; +:(code) +lease_tracer::lease_tracer() { Trace_stream = new trace_stream; } +lease_tracer::~lease_tracer() { + delete Trace_stream; + Trace_stream = NULL; +} + +//:: == Errors using traces :(before "End Includes") -#define CLEAR_TRACE delete Trace_stream, Trace_stream = new trace_stream; +#define raise (!Trace_stream ? (scroll_to_bottom_and_close_console(),++Trace_errors,cerr) /*do print*/ : Trace_stream->stream(Error_depth, "error")) -// Top-level helper. IMPORTANT: can't nest -#define trace(...) !Trace_stream ? cerr /*print nothing*/ : Trace_stream->stream(__VA_ARGS__) +:(before "End Globals") +int Trace_errors = 0; // used only when Trace_stream is NULL -// Just for debugging; 'git log' should never show any calls to 'dbg'. -#define dbg trace(0, "a") -#define DUMP(label) if (Trace_stream) cerr << Trace_stream->readable_contents(label); +// Fail scenarios that displayed (unexpected) errors. +// Expected errors should always be hidden and silently checked for. +:(before "End Test Teardown") +if (Passed && !Hide_errors && trace_contains_errors()) { + Passed = false; +} +:(code) +bool trace_contains_errors() { + return Trace_errors > 0 || trace_count("error") > 0; +} -// Errors are a special layer. -#define raise (!Trace_stream ? (scroll_to_bottom_and_close_console(),++Trace_errors,cerr) /*do print*/ : Trace_stream->stream(Error_depth, "error")) +:(before "End Includes") // If we aren't yet sure how to deal with some corner case, use assert_for_now // to indicate that it isn't an inviolable invariant. #define assert_for_now assert +#define raise_for_now raise //: Automatically close the console in some situations. :(before "End One-time Setup") @@ -209,57 +239,30 @@ void scroll_to_bottom_and_close_console() { cout << "\r\n"; tb_shutdown(); } - -// Inside tests, fail any tests that displayed (unexpected) errors. -// Expected errors in tests should always be hidden and silently checked for. -:(before "End Test Teardown") -if (Passed && !Hide_errors && trace_contains_errors()) { - Passed = false; -} -:(code) -bool trace_contains_errors() { - return Trace_errors > 0 || trace_count("error") > 0; -} - -:(before "End Types") -struct end {}; -:(code) -ostream& operator<<(ostream& os, end /*unused*/) { - if (Trace_stream) Trace_stream->newline(); - return os; -} - -:(before "End Globals") -bool Save_trace = false; // if set, write out trace to disk - -// Trace_stream is a resource, lease_tracer uses RAII to manage it. -:(before "End Types") -struct lease_tracer { - lease_tracer(); - ~lease_tracer(); -}; -:(code) -lease_tracer::lease_tracer() { Trace_stream = new trace_stream; } -lease_tracer::~lease_tracer() { - if (Save_trace) Trace_stream->save(); - delete Trace_stream, Trace_stream = NULL; -} :(before "End Includes") -#define START_TRACING_UNTIL_END_OF_SCOPE lease_tracer leased_tracer; -:(before "End Test Setup") -START_TRACING_UNTIL_END_OF_SCOPE +#include "termbox/termbox.h" + +//:: == Other assertions on traces +//: Primitives: +//: - CHECK_TRACE_CONTENTS(lines) +//: Assert that the trace contains the given lines (separated by newlines) +//: in order. There can be other intervening lines between them. +//: - CHECK_TRACE_DOESNT_CONTAIN(line) +//: - CHECK_TRACE_DOESNT_CONTAIN(label, contents) +//: Assert that the trace doesn't contain the given (single) line. +//: - CHECK_TRACE_COUNT(label, count) +//: Assert that the trace contains exactly 'count' lines with the given +//: 'label'. +//: - CHECK_TRACE_CONTAINS_ERRORS() +//: - CHECK_TRACE_DOESNT_CONTAIN_ERRORS() +//: - trace_count_prefix(label, prefix) +//: Count the number of trace lines with the given 'label' that start with +//: the given 'prefix'. :(before "End Includes") #define CHECK_TRACE_CONTENTS(...) check_trace_contents(__FUNCTION__, __FILE__, __LINE__, __VA_ARGS__) -#define CHECK_TRACE_CONTAINS_ERRORS() CHECK(trace_contains_errors()) -#define CHECK_TRACE_DOESNT_CONTAIN_ERRORS() \ - if (Passed && trace_contains_errors()) { \ - cerr << "\nF - " << __FUNCTION__ << "(" << __FILE__ << ":" << __LINE__ << "): unexpected errors\n"; \ - DUMP("error"); \ - Passed = false; \ - return; \ - } +#define CHECK_TRACE_DOESNT_CONTAIN(...) CHECK(trace_doesnt_contain(__VA_ARGS__)) #define CHECK_TRACE_COUNT(label, count) \ if (Passed && trace_count(label) != (count)) { \ @@ -270,7 +273,17 @@ START_TRACING_UNTIL_END_OF_SCOPE return; /* Currently we stop at the very first failure. */ \ } -#define CHECK_TRACE_DOESNT_CONTAIN(...) CHECK(trace_doesnt_contain(__VA_ARGS__)) +#define CHECK_TRACE_CONTAINS_ERRORS() CHECK(trace_contains_errors()) +#define CHECK_TRACE_DOESNT_CONTAIN_ERRORS() \ + if (Passed && trace_contains_errors()) { \ + cerr << "\nF - " << __FUNCTION__ << "(" << __FILE__ << ":" << __LINE__ << "): unexpected errors\n"; \ + DUMP("error"); \ + Passed = false; \ + return; \ + } + +// Allow scenarios to ignore trace lines generated during setup. +#define CLEAR_TRACE delete Trace_stream, Trace_stream = new trace_stream :(code) bool check_trace_contents(string FUNCTION, string FILE, int LINE, string expected) { @@ -305,25 +318,13 @@ bool check_trace_contents(string FUNCTION, string FILE, int LINE, string expecte return false; } -void split_label_contents(const string& s, string* label, string* contents) { - static const string delim(": "); - size_t pos = s.find(delim); - if (pos == string::npos) { - *label = ""; - *contents = trim(s); - } - else { - *label = trim(s.substr(0, pos)); - *contents = trim(s.substr(pos+SIZE(delim))); - } -} - -bool line_exists_anywhere(const string& label, const string& contents) { - for (vector::iterator p = Trace_stream->past_lines.begin(); p != Trace_stream->past_lines.end(); ++p) { - if (label != p->label) continue; - if (contents == trim(p->contents)) return true; +bool trace_doesnt_contain(string expected) { + vector tmp = split_first(expected, ": "); + if (SIZE(tmp) == 1) { + raise << expected << ": missing label or contents in trace line\n" << end(); + assert(false); } - return false; + return trace_count(tmp.at(0), tmp.at(1)) == 0; } int trace_count(string label) { @@ -354,17 +355,25 @@ int trace_count_prefix(string label, string prefix) { return result; } -bool trace_doesnt_contain(string label, string line) { - return trace_count(label, line) == 0; +void split_label_contents(const string& s, string* label, string* contents) { + static const string delim(": "); + size_t pos = s.find(delim); + if (pos == string::npos) { + *label = ""; + *contents = trim(s); + } + else { + *label = trim(s.substr(0, pos)); + *contents = trim(s.substr(pos+SIZE(delim))); + } } -bool trace_doesnt_contain(string expected) { - vector tmp = split_first(expected, ": "); - if (SIZE(tmp) == 1) { - raise << expected << ": missing label or contents in trace line\n" << end(); - assert(false); +bool line_exists_anywhere(const string& label, const string& contents) { + for (vector::iterator p = Trace_stream->past_lines.begin(); p != Trace_stream->past_lines.end(); ++p) { + if (label != p->label) continue; + if (contents == trim(p->contents)) return true; } - return trace_doesnt_contain(tmp.at(0), tmp.at(1)); + return false; } vector split(string s, string delim) { @@ -391,6 +400,54 @@ vector split_first(string s, string delim) { return result; } +//:: == Helpers for debugging using traces + +:(before "End Includes") +// To debug why a scenario is failing, dump its trace using '?'. +#define DUMP(label) if (Trace_stream) cerr << Trace_stream->readable_contents(label); + +// To add temporary prints to the trace, use 'dbg'. +// `git log` should never show any calls to 'dbg'. +#define dbg trace(0, "a") + +//: Dump the entire trace to file where it can be browsed offline. +//: Dump the trace as it happens; that way you get something even if the +//: program crashes. + +:(before "End Globals") +ofstream Trace_file; +:(before "End Commandline Options(*arg)") +else if (is_equal(*arg, "--trace")) { + Trace_stream = new trace_stream; + cerr << "saving trace to 'last_run'\n"; + Trace_file.open("last_run"); +} +:(before "End trace Commit") +if (Trace_file) { + Trace_file << std::setw(4) << t.depth << ' ' << t.label << ": " << t.contents << '\n'; +} +:(before "End One-time Setup") +atexit(cleanup_main); +:(code) +void cleanup_main() { + if (Trace_file) Trace_file.close(); + // End cleanup_main +} + +:(before "End trace_stream Methods") +string readable_contents(string label) { + string trim(const string& s); // prototype + ostringstream output; + label = trim(label); + for (vector::iterator p = past_lines.begin(); p != past_lines.end(); ++p) + if (label.empty() || label == p->label) + output << std::setw(4) << p->depth << ' ' << p->label << ": " << p->contents << '\n'; + return output.str(); +} + +//: Miscellaneous helpers. + +:(code) string trim(const string& s) { string::const_iterator first = s.begin(); while (first != s.end() && isspace(*first)) @@ -419,19 +476,3 @@ using std::ostringstream; #include using std::ifstream; using std::ofstream; - -#include "termbox/termbox.h" - -:(before "End Globals") -//: In future layers we'll use the depth field as follows: -//: -//: Errors will be depth 0. -//: Mu 'applications' will be able to use depths 1-100 as they like. -//: Primitive statements will occupy 101-9989 -extern const int Initial_callstack_depth = 101; -extern const int Max_callstack_depth = 9989; -//: Finally, details of primitive Mu statements will occupy depth 9990-9999 -//: (more on that later as well) -//: -//: 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/011load.cc b/011load.cc index 666f1c6e..575509ea 100644 --- a/011load.cc +++ b/011load.cc @@ -63,13 +63,13 @@ int slurp_recipe(istream& in) { // End Recipe Refinements if (result.name.empty()) raise << "empty result.name\n" << end(); - trace(9991, "parse") << "--- defining " << result.name << end(); + trace(101, "parse") << "--- defining " << result.name << end(); if (!contains_key(Recipe_ordinal, result.name)) put(Recipe_ordinal, result.name, Next_recipe_ordinal); result.ordinal = get(Recipe_ordinal, result.name); ++Next_recipe_ordinal; if (Recipe.find(get(Recipe_ordinal, result.name)) != Recipe.end()) { - trace(9991, "parse") << "already exists" << end(); + trace(101, "parse") << "already exists" << end(); if (should_check_for_redefine(result.name)) raise << "redefining recipe " << result.name << "\n" << end(); Recipe.erase(get(Recipe_ordinal, result.name)); @@ -90,7 +90,7 @@ void slurp_body(istream& in, recipe& result) { while (next_instruction(in, &curr)) { curr.original_string = to_original_string(curr); // End Rewrite Instruction(curr, recipe result) - trace(9992, "load") << "after rewriting: " << to_string(curr) << end(); + trace(102, "load") << "after rewriting: " << to_string(curr) << end(); if (!curr.is_empty()) result.steps.push_back(curr); } } @@ -126,7 +126,7 @@ bool next_instruction(istream& in, instruction* curr) { if (SIZE(words) == 1 && is_label_word(words.at(0))) { curr->is_label = true; curr->label = words.at(0); - trace(9993, "parse") << "label: " << curr->label << end(); + trace(103, "parse") << "label: " << curr->label << end(); if (!has_data(in)) { raise << "incomplete recipe at end of file (3)\n" << end(); return false; @@ -151,12 +151,12 @@ bool next_instruction(istream& in, instruction* curr) { for (; p != words.end(); ++p) curr->ingredients.push_back(reagent(*p)); - trace(9993, "parse") << "instruction: " << curr->name << end(); - trace(9993, "parse") << " number of ingredients: " << SIZE(curr->ingredients) << end(); + trace(103, "parse") << "instruction: " << curr->name << end(); + trace(103, "parse") << " number of ingredients: " << SIZE(curr->ingredients) << end(); for (vector::iterator p = curr->ingredients.begin(); p != curr->ingredients.end(); ++p) - trace(9993, "parse") << " ingredient: " << to_string(*p) << end(); + trace(103, "parse") << " ingredient: " << to_string(*p) << end(); for (vector::iterator p = curr->products.begin(); p != curr->products.end(); ++p) - trace(9993, "parse") << " product: " << to_string(*p) << end(); + trace(103, "parse") << " product: " << to_string(*p) << end(); if (!has_data(in)) { raise << "9: unbalanced '[' for recipe\n" << end(); return false; diff --git a/012transform.cc b/012transform.cc index f62349fa..758a286c 100644 --- a/012transform.cc +++ b/012transform.cc @@ -44,7 +44,7 @@ void initialize_transforms() { } void transform_all() { - trace(9990, "transform") << "=== transform_all()" << end(); + trace(100, "transform") << "=== transform_all()" << end(); // Begin transform_all for (int t = 0; t < SIZE(Transform); ++t) { for (map::iterator p = Recipe.begin(); p != Recipe.end(); ++p) { @@ -72,7 +72,7 @@ int Num_calls_to_transform_all = 0; :(code) void parse_int_reagents() { - trace(9991, "transform") << "--- parsing any uninitialized reagents as integers" << end(); + trace(101, "transform") << "--- parsing any uninitialized reagents as integers" << end(); for (map::iterator p = Recipe.begin(); p != Recipe.end(); ++p) { recipe& r = p->second; if (r.steps.empty()) continue; diff --git a/013update_operation.cc b/013update_operation.cc index 8366439d..c5a736f6 100644 --- a/013update_operation.cc +++ b/013update_operation.cc @@ -6,7 +6,7 @@ Transform.push_back(update_instruction_operations); // idempotent :(code) void update_instruction_operations(const recipe_ordinal r) { - trace(9991, "transform") << "--- compute instruction operations for recipe " << get(Recipe, r).name << end(); + trace(101, "transform") << "--- compute instruction operations for recipe " << get(Recipe, r).name << end(); recipe& caller = get(Recipe, r); //? cerr << "--- compute instruction operations for recipe " << caller.name << '\n'; for (int index = 0; index < SIZE(caller.steps); ++index) { diff --git a/019type_abbreviations.cc b/019type_abbreviations.cc index df797dfa..dfa214c9 100644 --- a/019type_abbreviations.cc +++ b/019type_abbreviations.cc @@ -50,7 +50,7 @@ void load_type_abbreviations(istream& in) { raise << "'type' conflict: '" << new_type_name << "' defined as both '" << names_to_string_without_quotes(get(Type_abbreviations, new_type_name)) << "' and '" << old << "'\n" << end(); return; } - trace(9990, "type") << "alias " << new_type_name << " = " << old << end(); + trace(100, "type") << "alias " << new_type_name << " = " << old << end(); type_tree* old_type = new_type_tree(old); put(Type_abbreviations, new_type_name, old_type); } @@ -168,17 +168,17 @@ void expand_type_abbreviations(const recipe_ordinal r) { } void expand_type_abbreviations(const recipe& caller) { - trace(9991, "transform") << "--- expand type abbreviations in recipe '" << caller.name << "'" << end(); + trace(101, "transform") << "--- expand type abbreviations in recipe '" << caller.name << "'" << end(); for (int i = 0; i < SIZE(caller.steps); ++i) { const instruction& inst = caller.steps.at(i); - trace(9991, "transform") << "instruction '" << to_original_string(inst) << end(); + trace(102, "transform") << "instruction '" << to_original_string(inst) << end(); for (long int i = 0; i < SIZE(inst.ingredients); ++i) { expand_type_abbreviations(inst.ingredients.at(i).type); - trace(9992, "transform") << "ingredient type after expanding abbreviations: " << names_to_string(inst.ingredients.at(i).type) << end(); + trace(102, "transform") << "ingredient type after expanding abbreviations: " << names_to_string(inst.ingredients.at(i).type) << end(); } for (long int i = 0; i < SIZE(inst.products); ++i) { expand_type_abbreviations(inst.products.at(i).type); - trace(9992, "transform") << "product type after expanding abbreviations: " << names_to_string(inst.products.at(i).type) << end(); + trace(102, "transform") << "product type after expanding abbreviations: " << names_to_string(inst.products.at(i).type) << end(); } } // End Expand Type Abbreviations(caller) diff --git a/020run.cc b/020run.cc index 74012216..5d466bbc 100644 --- a/020run.cc +++ b/020run.cc @@ -63,7 +63,7 @@ void run_current_routine() { while (should_continue_running(Current_routine)) { // beware: may modify Current_routine // Running One Instruction if (current_instruction().is_label) { ++current_step_index(); continue; } - trace(Initial_callstack_depth + Trace_stream->callstack_depth, "run") << to_string(current_instruction()) << end(); + trace(Callstack_depth, "run") << to_string(current_instruction()) << end(); //? if (Foo) cerr << "run: " << to_string(current_instruction()) << '\n'; if (get_or_insert(Memory, 0) != 0) { raise << "something wrote to location 0; this should never happen\n" << end(); @@ -113,6 +113,26 @@ void run_current_routine() { stop_running_current_routine:; } +//: Helpers for managing trace depths +//: +//: We're going to use trace depths primarily to segment code running at +//: different frames of the call stack. This will make it easy for the trace +//: browser to collapse over entire calls. +//: +//: The entire map of possible depths is as follows: +//: +//: Errors will be depth 0. +//: Mu 'applications' will be able to use depths 1-99 as they like. +//: Primitive statements will occupy 100 and up to Max_depth, organized by +//: stack frames. +:(before "End Globals") +extern const int Initial_callstack_depth = 100; +int Callstack_depth = Initial_callstack_depth; +:(before "End Reset") +Callstack_depth = Initial_callstack_depth; + +//: Other helpers for the VM. + :(code) //: hook replaced in a later layer bool should_continue_running(const routine* current_routine) { @@ -255,7 +275,7 @@ void load_file_or_directory(string filename) { cerr << "no such file '" << filename << "'\n" << end(); // don't raise, just warn. just in case it's just a name for a scenario to run. return; } - trace(9990, "load") << "=== " << filename << end(); + trace(2, "load") << "=== " << filename << end(); load(fin); fin.close(); } @@ -306,7 +326,7 @@ vector read_memory(reagent/*copy*/ x) { int size = size_of(x); for (int offset = 0; offset < size; ++offset) { double val = get_or_insert(Memory, x.value+offset); - trace("mem") << "location " << x.value+offset << " is " << no_scientific(val) << end(); + trace(Callstack_depth+1, "mem") << "location " << x.value+offset << " is " << no_scientific(val) << end(); result.push_back(val); } return result; @@ -333,7 +353,7 @@ void write_memory(reagent/*copy*/ x, const vector& data) { // End write_memory(x) Special-cases for (int offset = 0; offset < SIZE(data); ++offset) { assert(x.value+offset > 0); - trace("mem") << "storing " << no_scientific(data.at(offset)) << " in location " << x.value+offset << end(); + trace(Callstack_depth+1, "mem") << "storing " << no_scientific(data.at(offset)) << " in location " << x.value+offset << end(); //? if (Foo) cerr << "mem: storing " << no_scientific(data.at(offset)) << " in location " << x.value+offset << '\n'; put(Memory, x.value+offset, data.at(offset)); } @@ -392,10 +412,7 @@ void run(const string& form) { vector tmp = load(form); transform_all(); if (tmp.empty()) return; - if (trace_contains_errors()) { - if (Save_trace && Trace_stream) Trace_stream->save(); - return; - } + if (trace_contains_errors()) return; // if a test defines main, it probably wants to start there regardless of // definition order if (contains_key(Recipe, get(Recipe_ordinal, "main"))) diff --git a/021check_instruction.cc b/021check_instruction.cc index 6347dfb3..5bc7fa9c 100644 --- a/021check_instruction.cc +++ b/021check_instruction.cc @@ -13,7 +13,7 @@ Transform.push_back(check_instruction); // idempotent :(code) void check_instruction(const recipe_ordinal r) { - trace(9991, "transform") << "--- perform checks for recipe " << get(Recipe, r).name << end(); + trace(101, "transform") << "--- perform checks for recipe " << get(Recipe, r).name << end(); map > metadata; for (int i = 0; i < SIZE(get(Recipe, r).steps); ++i) { instruction& inst = get(Recipe, r).steps.at(i); diff --git a/024jump.cc b/024jump.cc index 14c14297..5b95fd19 100644 --- a/024jump.cc +++ b/024jump.cc @@ -33,7 +33,7 @@ case JUMP: { case JUMP: { assert(current_instruction().ingredients.at(0).initialized); current_step_index() += ingredients.at(0).at(0)+1; - trace(9998, "run") << "jumping to instruction " << current_step_index() << end(); + trace(Callstack_depth+1, "run") << "jumping to instruction " << current_step_index() << end(); // skip rest of this instruction write_products = false; fall_through_to_next_instruction = false; @@ -91,11 +91,11 @@ case JUMP_IF: { case JUMP_IF: { assert(current_instruction().ingredients.at(1).initialized); if (!scalar_ingredient(ingredients, 0)) { - trace(9998, "run") << "jump-if fell through" << end(); + trace(Callstack_depth+1, "run") << "jump-if fell through" << end(); break; } current_step_index() += ingredients.at(1).at(0)+1; - trace(9998, "run") << "jumping to instruction " << current_step_index() << end(); + trace(Callstack_depth+1, "run") << "jumping to instruction " << current_step_index() << end(); // skip rest of this instruction write_products = false; fall_through_to_next_instruction = false; @@ -162,11 +162,11 @@ case JUMP_UNLESS: { case JUMP_UNLESS: { assert(current_instruction().ingredients.at(1).initialized); if (scalar_ingredient(ingredients, 0)) { - trace(9998, "run") << "jump-unless fell through" << end(); + trace(Callstack_depth+1, "run") << "jump-unless fell through" << end(); break; } current_step_index() += ingredients.at(1).at(0)+1; - trace(9998, "run") << "jumping to instruction " << current_step_index() << end(); + trace(Callstack_depth+1, "run") << "jumping to instruction " << current_step_index() << end(); // skip rest of this instruction write_products = false; fall_through_to_next_instruction = false; diff --git a/026call.cc b/026call.cc index c6077cd9..1f130ef5 100644 --- a/026call.cc +++ b/026call.cc @@ -60,11 +60,9 @@ struct routine { }; :(code) routine::routine(recipe_ordinal r) { - if (Trace_stream) { - ++Trace_stream->callstack_depth; - trace("trace") << "new routine; incrementing callstack depth to " << Trace_stream->callstack_depth << end(); - assert(Trace_stream->callstack_depth < 9000); // 9998-101 plus cushion - } + ++Callstack_depth; + trace(Callstack_depth+1, "trace") << "new routine; incrementing callstack depth to " << Callstack_depth << end(); + assert(Callstack_depth < Max_depth); calls.push_front(call(r)); // End routine Constructor } @@ -151,11 +149,9 @@ if (!contains_key(Recipe, inst.operation)) { default: { if (contains_key(Recipe, current_instruction().operation)) { // error already raised in Checks above // not a primitive; look up the book of recipes - if (Trace_stream) { - ++Trace_stream->callstack_depth; - trace("trace") << "incrementing callstack depth to " << Trace_stream->callstack_depth << end(); - assert(Trace_stream->callstack_depth < 9000); // 9998-101 plus cushion - } + ++Callstack_depth; + trace(Callstack_depth+1, "trace") << "incrementing callstack depth to " << Callstack_depth << end(); + assert(Callstack_depth < Max_depth); const call& caller_frame = current_call(); Current_routine->calls.push_front(call(to_instruction(caller_frame).operation)); finish_call_housekeeping(to_instruction(caller_frame), ingredients); @@ -202,11 +198,9 @@ const vector& routine::steps() const { // it, and the one below that, and so on while (current_step_index() >= SIZE(Current_routine->steps())) { // Falling Through End Of Recipe - if (Trace_stream) { - trace("trace") << "fall-through: exiting " << current_recipe_name() << "; decrementing callstack depth from " << Trace_stream->callstack_depth << end(); - --Trace_stream->callstack_depth; - assert(Trace_stream->callstack_depth >= 0); - } + trace(Callstack_depth+1, "trace") << "fall-through: exiting " << current_recipe_name() << "; decrementing callstack depth from " << Callstack_depth << end(); + --Callstack_depth; + assert(Callstack_depth >= 0); Current_routine->calls.pop_front(); if (Current_routine->calls.empty()) goto stop_running_current_routine; // Complete Call Fallthrough diff --git a/028call_return.cc b/028call_return.cc index c8c1bca6..af158884 100644 --- a/028call_return.cc +++ b/028call_return.cc @@ -37,19 +37,17 @@ case RETURN: { :(before "End Primitive Recipe Implementations") case RETURN: { // Begin Return - if (Trace_stream) { - trace("trace") << current_instruction().name << ": decrementing callstack depth from " << Trace_stream->callstack_depth << end(); - --Trace_stream->callstack_depth; - if (Trace_stream->callstack_depth < 0) { - Current_routine->calls.clear(); - goto stop_running_current_routine; - } + trace(Callstack_depth+1, "trace") << current_instruction().name << ": decrementing callstack depth from " << Callstack_depth << end(); + --Callstack_depth; + if (Callstack_depth < 0) { + Current_routine->calls.clear(); + goto stop_running_current_routine; } 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; for (int i = 0; i < SIZE(ingredients); ++i) - trace(9998, "run") << "result " << i << " is " << to_string(ingredients.at(i)) << end(); + trace(Callstack_depth+1, "run") << "result " << i << " is " << to_string(ingredients.at(i)) << end(); // make return products available to caller copy(ingredients.begin(), ingredients.end(), inserter(products, products.begin())); // End Return diff --git a/029tools.cc b/029tools.cc index be3c04e2..56ac861c 100644 --- a/029tools.cc +++ b/029tools.cc @@ -169,20 +169,6 @@ case _CLEAR_TRACE: { break; } -:(before "End Primitive Recipe Declarations") -_SAVE_TRACE, -:(before "End Primitive Recipe Numbers") -put(Recipe_ordinal, "$save-trace", _SAVE_TRACE); -:(before "End Primitive Recipe Checks") -case _SAVE_TRACE: { - break; -} -:(before "End Primitive Recipe Implementations") -case _SAVE_TRACE: { - if (Save_trace) Trace_stream->save(); - break; -} - //:: 'cheating' by using the host system :(before "End Primitive Recipe Declarations") @@ -197,7 +183,7 @@ case _PRINT: { case _PRINT: { for (int i = 0; i < SIZE(ingredients); ++i) { if (is_literal(current_instruction().ingredients.at(i))) { - trace(9998, "run") << "$print: " << current_instruction().ingredients.at(i).name << end(); + trace(Callstack_depth+1, "run") << "$print: " << current_instruction().ingredients.at(i).name << end(); if (!has_property(current_instruction().ingredients.at(i), "newline")) { cout << current_instruction().ingredients.at(i).name; } @@ -210,7 +196,7 @@ case _PRINT: { // End $print Special-cases else { for (int j = 0; j < SIZE(ingredients.at(i)); ++j) { - trace(9998, "run") << "$print: " << ingredients.at(i).at(j) << end(); + trace(Callstack_depth+1, "run") << "$print: " << ingredients.at(i).at(j) << end(); if (j > 0) cout << " "; cout << no_scientific(ingredients.at(i).at(j)); } diff --git a/030container.cc b/030container.cc index aff65a1d..ca2d6743 100644 --- a/030container.cc +++ b/030container.cc @@ -198,11 +198,11 @@ case GET: { int src = base_address; for (int i = 0; i < offset; ++i) src += size_of(element_type(base.type, i)); - trace(9998, "run") << "address to copy is " << src << end(); + trace(Callstack_depth+1, "run") << "address to copy is " << src << end(); //: use base.type rather than base_type because later layers will introduce compound types reagent/*copy*/ element = element_type(base.type, offset); element.set_value(src); - trace(9998, "run") << "its type is " << names_to_string(element.type) << end(); + trace(Callstack_depth+1, "run") << "its type is " << names_to_string(element.type) << end(); // Read element products.push_back(read_memory(element)); break; @@ -355,13 +355,13 @@ case PUT: { int address = base_address; for (int i = 0; i < offset; ++i) address += size_of(element_type(base.type, i)); - trace(9998, "run") << "address to copy to is " << address << end(); + trace(Callstack_depth+1, "run") << "address to copy to is " << address << end(); // optimization: directly write the element rather than updating 'product' // and writing the entire container // Write Memory in PUT in Run write_products = false; for (int i = 0; i < SIZE(ingredients.at(2)); ++i) { - trace("mem") << "storing " << no_scientific(ingredients.at(2).at(i)) << " in location " << address+i << end(); + trace(Callstack_depth+1, "mem") << "storing " << no_scientific(ingredients.at(2).at(i)) << " in location " << address+i << end(); put(Memory, address+i, ingredients.at(2).at(i)); } break; @@ -452,12 +452,12 @@ void insert_container(const string& command, kind_of_type kind, istream& in) { return; } // End container Name Refinements - trace(9991, "parse") << "--- defining " << command << ' ' << name << end(); + trace(101, "parse") << "--- defining " << command << ' ' << name << end(); if (!contains_key(Type_ordinal, name) || get(Type_ordinal, name) == 0) { put(Type_ordinal, name, Next_type_ordinal++); } - trace("parse") << "type number: " << get(Type_ordinal, name) << end(); + trace(102, "parse") << "type number: " << get(Type_ordinal, name) << end(); skip_bracket(in, "'"+command+"' must begin with '['"); type_info& info = get_or_insert(Type, get(Type_ordinal, name)); if (info.Num_calls_to_transform_all_at_first_definition == -1) { @@ -492,7 +492,7 @@ void insert_container(const string& command, kind_of_type kind, istream& in) { info.elements.push_back(reagent(element)); expand_type_abbreviations(info.elements.back().type); // todo: use abbreviation before declaration replace_unknown_types_with_unique_ordinals(info.elements.back().type, info); - trace(9993, "parse") << " element: " << to_string(info.elements.back()) << end(); + trace(103, "parse") << " element: " << to_string(info.elements.back()) << end(); // End Load Container Element Definition } } @@ -602,7 +602,7 @@ Transform.push_back(check_or_set_invalid_types); // idempotent :(code) void check_or_set_invalid_types(const recipe_ordinal r) { recipe& caller = get(Recipe, r); - trace(9991, "transform") << "--- check for invalid types in recipe " << caller.name << end(); + trace(101, "transform") << "--- check for invalid types in recipe " << caller.name << end(); for (int index = 0; index < SIZE(caller.steps); ++index) { instruction& inst = caller.steps.at(index); for (int i = 0; i < SIZE(inst.ingredients); ++i) diff --git a/031merge.cc b/031merge.cc index c56579a5..99b6846a 100644 --- a/031merge.cc +++ b/031merge.cc @@ -114,7 +114,7 @@ Transform.push_back(check_merge_calls); // idempotent :(code) void check_merge_calls(const recipe_ordinal r) { const recipe& caller = get(Recipe, r); - trace(9991, "transform") << "--- type-check merge instructions in recipe " << caller.name << end(); + trace(101, "transform") << "--- type-check merge instructions in recipe " << caller.name << end(); for (int i = 0; i < SIZE(caller.steps); ++i) { const instruction& inst = caller.steps.at(i); if (inst.name != "merge") continue; @@ -145,7 +145,7 @@ void check_merge_call(const vector& ingredients, const reagent& product state.data.push(merge_check_point(product, 0)); while (true) { assert(!state.data.empty()); - trace("transform") << ingredient_index << " vs " << SIZE(ingredients) << end(); + trace(102, "transform") << ingredient_index << " vs " << SIZE(ingredients) << end(); if (ingredient_index >= SIZE(ingredients)) { raise << maybe(caller.name) << "too few ingredients in '" << to_original_string(inst) << "'\n" << end(); return; @@ -161,7 +161,7 @@ void check_merge_call(const vector& ingredients, const reagent& product if (state.data.top().container_element_index == 0 && types_coercible(container, inst.ingredients.at(ingredient_index))) return; const reagent& expected_ingredient = element_type(container.type, state.data.top().container_element_index); - trace("transform") << "checking container " << to_string(container) << " || " << to_string(expected_ingredient) << " vs ingredient " << ingredient_index << end(); + trace(102, "transform") << "checking container " << to_string(container) << " || " << to_string(expected_ingredient) << " vs ingredient " << ingredient_index << end(); // if the current element is the ingredient we expect, move on to the next element/ingredient if (types_coercible(expected_ingredient, ingredients.at(ingredient_index))) { ++ingredient_index; diff --git a/032array.cc b/032array.cc index 25d91b60..7f36411f 100644 --- a/032array.cc +++ b/032array.cc @@ -57,10 +57,10 @@ case CREATE_ARRAY: { array_length_from_type = array_length_from_type->left; int array_length = to_integer(array_length_from_type->name); // initialize array length, so that size_of will work - trace("mem") << "storing " << array_length << " in location " << base_address << end(); + trace(Callstack_depth+1, "mem") << "storing " << array_length << " in location " << base_address << end(); put(Memory, base_address, array_length); // in array elements int size = size_of(product); // in locations - trace(9998, "run") << "creating array from " << size << " locations" << end(); + trace(Callstack_depth+1, "run") << "creating array from " << size << " locations" << end(); // initialize array for (int i = 1; i <= size_of(product); ++i) put(Memory, base_address+i, 0); @@ -274,7 +274,7 @@ case INDEX: { reagent/*copy*/ base = current_instruction().ingredients.at(0); // Update INDEX base in Run int base_address = base.value; - trace(9998, "run") << "base address is " << base_address << end(); + trace(Callstack_depth+1, "run") << "base address is " << base_address << end(); if (base_address == 0) { raise << maybe(current_recipe_name()) << "tried to access location 0 in '" << to_original_string(current_instruction()) << "'\n" << end(); break; @@ -288,8 +288,8 @@ case INDEX: { } reagent/*local*/ element(copy_array_element(base.type)); element.set_value(base_address + /*skip length*/1 + index_val.at(0)*size_of(element.type)); - trace(9998, "run") << "address to copy is " << element.value << end(); - trace(9998, "run") << "its type is " << to_string(element.type) << end(); + trace(Callstack_depth+1, "run") << "address to copy is " << element.value << end(); + trace(Callstack_depth+1, "run") << "its type is " << to_string(element.type) << end(); // Read element products.push_back(read_memory(element)); break; @@ -451,14 +451,14 @@ case PUT_INDEX: { break; } int address = base_address + /*skip length*/1 + index_val.at(0)*size_of(array_element(base.type)); - trace(9998, "run") << "address to copy to is " << address << end(); + trace(Callstack_depth+1, "run") << "address to copy to is " << address << end(); // optimization: directly write the element rather than updating 'product' // and writing the entire array write_products = false; vector value = read_memory(current_instruction().ingredients.at(2)); // Write Memory in PUT_INDEX in Run for (int i = 0; i < SIZE(value); ++i) { - trace("mem") << "storing " << no_scientific(value.at(i)) << " in location " << address+i << end(); + trace(Callstack_depth+1, "mem") << "storing " << no_scientific(value.at(i)) << " in location " << address+i << end(); put(Memory, address+i, value.at(i)); } break; diff --git a/033exclusive_container.cc b/033exclusive_container.cc index c2d69f60..5c57972e 100644 --- a/033exclusive_container.cc +++ b/033exclusive_container.cc @@ -150,19 +150,19 @@ case MAYBE_CONVERT: { write_products = false; if (tag == static_cast(get_or_insert(Memory, base_address))) { const reagent& variant = variant_type(base, tag); - trace("mem") << "storing 1 in location " << status.value << end(); + trace(Callstack_depth+1, "mem") << "storing 1 in location " << status.value << end(); put(Memory, status.value, 1); if (!is_dummy(product)) { // Write Memory in Successful MAYBE_CONVERT in Run for (int i = 0; i < size_of(variant); ++i) { double val = get_or_insert(Memory, base_address+/*skip tag*/1+i); - trace("mem") << "storing " << no_scientific(val) << " in location " << product.value+i << end(); + trace(Callstack_depth+1, "mem") << "storing " << no_scientific(val) << " in location " << product.value+i << end(); put(Memory, product.value+i, val); } } } else { - trace("mem") << "storing 0 in location " << status.value << end(); + trace(Callstack_depth+1, "mem") << "storing 0 in location " << status.value << end(); put(Memory, status.value, 0); } break; @@ -305,7 +305,7 @@ $error: 0 :(before "End check_merge_call Special-cases") case EXCLUSIVE_CONTAINER: { assert(state.data.top().container_element_index == 0); - trace("transform") << "checking exclusive container " << to_string(container) << " vs ingredient " << ingredient_index << end(); + trace(102, "transform") << "checking exclusive container " << to_string(container) << " vs ingredient " << ingredient_index << end(); // easy case: exact match if (types_strictly_match(container, inst.ingredients.at(ingredient_index))) return; @@ -320,7 +320,7 @@ case EXCLUSIVE_CONTAINER: { return; } const reagent& variant = variant_type(container, ingredient.value); - trace("transform") << "tag: " << ingredient.value << end(); + trace(102, "transform") << "tag: " << ingredient.value << end(); // replace union with its variant state.data.pop(); state.data.push(merge_check_point(variant, 0)); diff --git a/034address.cc b/034address.cc index a71f5194..af98fc14 100644 --- a/034address.cc +++ b/034address.cc @@ -215,7 +215,7 @@ Transform.push_back(transform_new_to_allocate); // idempotent :(code) void transform_new_to_allocate(const recipe_ordinal r) { - trace(9991, "transform") << "--- convert 'new' to 'allocate' for recipe " << get(Recipe, r).name << end(); + trace(101, "transform") << "--- convert 'new' to 'allocate' for recipe " << get(Recipe, r).name << end(); for (int i = 0; i < SIZE(get(Recipe, r).steps); ++i) { instruction& inst = get(Recipe, r).steps.at(i); // Convert 'new' To 'allocate' @@ -224,7 +224,7 @@ void transform_new_to_allocate(const recipe_ordinal r) { inst.operation = ALLOCATE; type_tree* type = new_type_tree(inst.ingredients.at(0).name); inst.ingredients.at(0).set_value(size_of(type)); - trace(9992, "new") << "size of '" << inst.ingredients.at(0).name << "' is " << inst.ingredients.at(0).value << end(); + trace(102, "new") << "size of '" << inst.ingredients.at(0).name << "' is " << inst.ingredients.at(0).value << end(); delete type; } } @@ -245,7 +245,7 @@ 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 << end(); +trace(Callstack_depth+1, "new") << "routine allocated memory from " << alloc << " to " << alloc_max << end(); :(before "End Primitive Recipe Declarations") ALLOCATE, @@ -259,16 +259,16 @@ case ALLOCATE: { Next_alloc_id++; if (SIZE(ingredients) > 1) { // array allocation - trace("mem") << "array length is " << ingredients.at(1).at(0) << end(); + trace(Callstack_depth+1, "mem") << "array length is " << ingredients.at(1).at(0) << end(); size = /*space for length*/1 + size*ingredients.at(1).at(0); } int result = allocate(size); // initialize alloc-id in payload - trace("mem") << "storing alloc-id " << alloc_id << " in location " << result << end(); + trace(Callstack_depth+1, "mem") << "storing alloc-id " << alloc_id << " in location " << result << end(); put(Memory, result, alloc_id); if (SIZE(current_instruction().ingredients) > 1) { // initialize array length - trace("mem") << "storing array length " << ingredients.at(1).at(0) << " in location " << result+/*skip alloc id*/1 << end(); + trace(Callstack_depth+1, "mem") << "storing array length " << ingredients.at(1).at(0) << " in location " << result+/*skip alloc id*/1 << end(); put(Memory, result+/*skip alloc id*/1, ingredients.at(1).at(0)); } products.resize(1); @@ -280,7 +280,7 @@ case ALLOCATE: { int allocate(int size) { // include space for alloc id ++size; - trace("mem") << "allocating size " << size << end(); + trace(Callstack_depth+1, "mem") << "allocating size " << size << end(); //? Total_alloc += size; //? ++Num_alloc; // Allocate Special-cases @@ -288,10 +288,10 @@ int allocate(int size) { // really crappy at the moment ensure_space(size); const int result = Current_routine->alloc; - trace("mem") << "new alloc: " << result << end(); + trace(Callstack_depth+1, "mem") << "new alloc: " << result << end(); // initialize allocated space for (int address = result; address < result+size; ++address) { - trace("mem") << "storing 0 in location " << address << end(); + trace(Callstack_depth+1, "mem") << "storing 0 in location " << address << end(); put(Memory, address, 0); } Current_routine->alloc += size; @@ -325,7 +325,7 @@ void ensure_space(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 << end(); + trace(Callstack_depth+1, "new") << "routine allocated memory from " << Current_routine->alloc << " to " << Current_routine->alloc_max << end(); } } diff --git a/035lookup.cc b/035lookup.cc index 02c2ab3f..b7c05201 100644 --- a/035lookup.cc +++ b/035lookup.cc @@ -88,7 +88,7 @@ void lookup_memory(reagent& x) { void lookup_memory_core(reagent& x, bool check_for_null) { double address = x.value + /*skip alloc id in address*/1; double new_value = get_or_insert(Memory, address); - trace("mem") << "location " << address << " contains " << no_scientific(new_value) << end(); + trace(Callstack_depth+1, "mem") << "location " << address << " contains " << no_scientific(new_value) << end(); // check for null if (check_for_null && new_value == 0) { if (Current_routine) { diff --git a/036abandon.cc b/036abandon.cc index c2b9125e..4dcf572f 100644 --- a/036abandon.cc +++ b/036abandon.cc @@ -67,7 +67,7 @@ void abandon(int address, int payload_size) { for (int curr = address+1; curr < address+payload_size; ++curr) put(Memory, curr, 0); // append existing free list to address - trace("abandon") << "saving " << address << " in free-list of size " << payload_size << end(); + trace(Callstack_depth+1, "abandon") << "saving " << address << " in free-list of size " << payload_size << end(); put(Memory, address+/*skip invalid alloc-id*/1, get_or_insert(Current_routine->free_list, payload_size)); put(Current_routine->free_list, payload_size, address); } @@ -80,9 +80,9 @@ int payload_size(reagent/*copy*/ x) { :(after "Allocate Special-cases") if (get_or_insert(Current_routine->free_list, size)) { - trace("abandon") << "picking up space from free-list of size " << size << end(); + trace(Callstack_depth+1, "abandon") << "picking up space from free-list of size " << size << end(); int result = get_or_insert(Current_routine->free_list, size); - trace("mem") << "new alloc from free list: " << result << end(); + trace(Callstack_depth+1, "mem") << "new alloc from free list: " << result << end(); put(Current_routine->free_list, size, get_or_insert(Memory, result+/*skip alloc id*/1)); // clear 'deleted' tag put(Memory, result, 0); diff --git a/038new_text.cc b/038new_text.cc index 7e3c02f6..10b819a3 100644 --- a/038new_text.cc +++ b/038new_text.cc @@ -31,7 +31,7 @@ if (inst.name == "new" && !inst.ingredients.empty() && is_literal_text(inst.ingr products.resize(1); products.at(0).push_back(/*alloc id*/0); products.at(0).push_back(new_mu_text(current_instruction().ingredients.at(0).name)); - trace("mem") << "new string alloc: " << products.at(0).at(0) << end(); + trace(Callstack_depth+1, "mem") << "new string alloc: " << products.at(0).at(0) << end(); break; } @@ -44,7 +44,7 @@ int new_mu_text(const string& contents) { int result = allocate(/*array length*/1 + string_length); int curr_address = result; ++curr_address; // skip alloc id - trace("mem") << "storing string length " << string_length << " in location " << curr_address << end(); + trace(Callstack_depth+1, "mem") << "storing string length " << string_length << " in location " << curr_address << end(); put(Memory, curr_address, string_length); ++curr_address; // skip length int curr = 0; @@ -53,7 +53,7 @@ int new_mu_text(const string& contents) { uint32_t curr_character; assert(curr < SIZE(contents)); tb_utf8_char_to_unicode(&curr_character, &raw_contents[curr]); - trace("mem") << "storing string character " << curr_character << " in location " << curr_address << end(); + trace(Callstack_depth+1, "mem") << "storing string character " << curr_character << " in location " << curr_address << end(); put(Memory, curr_address, curr_character); curr += tb_utf8_char_length(raw_contents[curr]); ++curr_address; diff --git a/040brace.cc b/040brace.cc index b3006456..8eead4ab 100644 --- a/040brace.cc +++ b/040brace.cc @@ -39,15 +39,15 @@ void transform_braces(const recipe_ordinal r) { const bool OPEN = false, CLOSE = true; // use signed integer for step index because we'll be doing arithmetic on it list > braces; - trace(9991, "transform") << "--- transform braces for recipe " << get(Recipe, r).name << end(); + trace(101, "transform") << "--- transform braces for recipe " << get(Recipe, r).name << end(); for (int index = 0; index < SIZE(get(Recipe, r).steps); ++index) { const instruction& inst = get(Recipe, r).steps.at(index); if (inst.label == "{") { - trace(9993, "transform") << maybe(get(Recipe, r).name) << "push (open, " << index << ")" << end(); + trace(103, "transform") << maybe(get(Recipe, r).name) << "push (open, " << index << ")" << end(); braces.push_back(pair(OPEN, index)); } if (inst.label == "}") { - trace(9993, "transform") << "push (close, " << index << ")" << end(); + trace(103, "transform") << "push (close, " << index << ")" << end(); braces.push_back(pair(CLOSE, index)); } } @@ -73,7 +73,7 @@ void transform_braces(const recipe_ordinal r) { && inst.name != "break" && inst.name != "break-if" && inst.name != "break-unless") { - trace(9992, "transform") << inst.name << " ..." << end(); + trace(102, "transform") << inst.name << " ..." << end(); continue; } // check for errors @@ -101,14 +101,14 @@ void transform_braces(const recipe_ordinal r) { if (inst.name.find("-if") != string::npos || inst.name.find("-unless") != string::npos) { // conditional branches check arg 1 if (SIZE(inst.ingredients) > 1 && is_literal(inst.ingredients.at(1))) { - trace(9992, "transform") << inst.name << ' ' << inst.ingredients.at(1).name << ":offset" << end(); + trace(102, "transform") << inst.name << ' ' << inst.ingredients.at(1).name << ":offset" << end(); continue; } } else { // unconditional branches check arg 0 if (!inst.ingredients.empty() && is_literal(inst.ingredients.at(0))) { - trace(9992, "transform") << "jump " << inst.ingredients.at(0).name << ":offset" << end(); + trace(102, "transform") << "jump " << inst.ingredients.at(0).name << ":offset" << end(); continue; } } @@ -124,9 +124,9 @@ void transform_braces(const recipe_ordinal r) { inst.ingredients.push_back(target); // log computed target if (inst.name == "jump") - trace(9992, "transform") << "jump " << no_scientific(target.value) << ":offset" << end(); + trace(102, "transform") << "jump " << no_scientific(target.value) << ":offset" << end(); else - trace(9992, "transform") << inst.name << ' ' << inst.ingredients.at(0).name << ", " << no_scientific(target.value) << ":offset" << end(); + trace(102, "transform") << inst.name << ' ' << inst.ingredients.at(0).name << ", " << no_scientific(target.value) << ":offset" << end(); } } diff --git a/042name.cc b/042name.cc index 88343495..5846b5b4 100644 --- a/042name.cc +++ b/042name.cc @@ -36,7 +36,7 @@ Name = Name_snapshot; :(code) void transform_names(const recipe_ordinal r) { recipe& caller = get(Recipe, r); - trace(9991, "transform") << "--- transform names for recipe " << caller.name << end(); + trace(101, "transform") << "--- transform names for recipe " << caller.name << end(); bool names_used = false; bool numeric_locations_used = false; map& names = Name[r]; @@ -78,7 +78,7 @@ void transform_names(const recipe_ordinal r) { if (is_named_location(product)) names_used = true; if (is_integer(product.name)) continue; if (names.find(product.name) == names.end()) { - trace(9993, "name") << "assign " << product.name << " " << curr_idx << end(); + trace(103, "name") << "assign " << product.name << " " << curr_idx << end(); names[product.name] = curr_idx; curr_idx += size_of(product); } @@ -282,7 +282,7 @@ if (inst.name == "get" || inst.name == "get-location" || inst.name == "put") { type_ordinal base_type = skip_addresses(inst.ingredients.at(0).type); if (contains_key(Type, base_type)) { // otherwise we'll raise an error elsewhere inst.ingredients.at(1).set_value(find_element_offset(base_type, inst.ingredients.at(1).name, get(Recipe, r).name)); - trace(9993, "name") << "element " << inst.ingredients.at(1).name << " of type " << get(Type, base_type).name << " is at offset " << no_scientific(inst.ingredients.at(1).value) << end(); + trace(103, "name") << "element " << inst.ingredients.at(1).name << " of type " << get(Type, base_type).name << " is at offset " << no_scientific(inst.ingredients.at(1).value) << end(); } } } @@ -330,7 +330,7 @@ if (inst.name == "maybe-convert") { type_ordinal base_type = skip_addresses(inst.ingredients.at(0).type); if (contains_key(Type, base_type)) { // otherwise we'll raise an error elsewhere inst.ingredients.at(1).set_value(find_element_offset(base_type, inst.ingredients.at(1).name, get(Recipe, r).name)); - trace(9993, "name") << "variant " << inst.ingredients.at(1).name << " of type " << get(Type, base_type).name << " has tag " << no_scientific(inst.ingredients.at(1).value) << end(); + trace(103, "name") << "variant " << inst.ingredients.at(1).name << " of type " << get(Type, base_type).name << " has tag " << no_scientific(inst.ingredients.at(1).value) << end(); } } } diff --git a/043space.cc b/043space.cc index d348f736..6028ef0d 100644 --- a/043space.cc +++ b/043space.cc @@ -264,7 +264,7 @@ void check_default_space(const recipe_ordinal r) { // End check_default_space Special-cases // assume recipes with only numeric addresses know what they're doing (usually tests) if (!contains_non_special_name(r)) return; - trace(9991, "transform") << "--- check that recipe " << caller.name << " sets default-space" << end(); + trace(101, "transform") << "--- check that recipe " << caller.name << " sets default-space" << end(); if (caller.steps.empty()) return; if (!starts_by_setting_default_space(caller)) raise << caller.name << " does not seem to start with 'local-scope' or 'default-space'\n" << end(); diff --git a/045closure_name.cc b/045closure_name.cc index 6b2defd3..b4a8ea24 100644 --- a/045closure_name.cc +++ b/045closure_name.cc @@ -42,7 +42,7 @@ Transform.push_back(collect_surrounding_spaces); // idempotent :(code) void collect_surrounding_spaces(const recipe_ordinal r) { - trace(9991, "transform") << "--- collect surrounding spaces for recipe " << get(Recipe, r).name << end(); + trace(101, "transform") << "--- collect surrounding spaces for recipe " << get(Recipe, r).name << end(); for (int i = 0; i < SIZE(get(Recipe, r).steps); ++i) { const instruction& inst = get(Recipe, r).steps.at(i); if (inst.is_label) continue; @@ -69,7 +69,7 @@ void collect_surrounding_spaces(const recipe_ordinal r) { raise << "recipe '" << get(Recipe, r).name << "' can have only one 'surrounding' recipe but has '" << get(Recipe, get(Surrounding_space, r)).name << "' and '" << surrounding_recipe_name << "'\n" << end(); continue; } - trace(9993, "name") << "lexically surrounding space for recipe " << get(Recipe, r).name << " comes from " << surrounding_recipe_name << end(); + trace(103, "name") << "lexically surrounding space for recipe " << get(Recipe, r).name << " comes from " << surrounding_recipe_name << end(); if (!contains_key(Recipe_ordinal, surrounding_recipe_name)) { raise << "can't find recipe providing surrounding space for '" << get(Recipe, r).name << "'; looking for '" << surrounding_recipe_name << "'\n" << end(); continue; diff --git a/046check_type_by_name.cc b/046check_type_by_name.cc index ba40f521..6042068a 100644 --- a/046check_type_by_name.cc +++ b/046check_type_by_name.cc @@ -34,7 +34,7 @@ struct name_lt { :(code) void check_or_set_types_by_name(const recipe_ordinal r) { recipe& caller = get(Recipe, r); - trace(9991, "transform") << "--- deduce types for recipe " << caller.name << end(); + trace(101, "transform") << "--- deduce types for recipe " << caller.name << end(); for (int i = 0; i < SIZE(caller.steps); ++i) { instruction& inst = caller.steps.at(i); for (int in = 0; in < SIZE(inst.ingredients); ++in) @@ -62,7 +62,7 @@ void deduce_missing_type(set& known_types, reagent& x, const r if (known_types.find(x) == known_types.end()) return; const reagent& exemplar = *known_types.find(x); x.type = new type_tree(*exemplar.type); - trace(9992, "transform") << x.name << " <= " << names_to_string(x.type) << end(); + trace(102, "transform") << x.name << " <= " << names_to_string(x.type) << end(); // spaces are special; their type includes their /names property if (is_mu_space(x) && !has_property(x, "names")) { if (!has_property(exemplar, "names")) { @@ -82,7 +82,7 @@ void check_type(set& known_types, const reagent& x, const reci return; } if (known_types.find(x) == known_types.end()) { - trace(9992, "transform") << x.name << " => " << names_to_string(x.type) << end(); + trace(102, "transform") << x.name << " => " << names_to_string(x.type) << end(); known_types.insert(x); } if (!types_strictly_match(known_types.find(x)->type, x.type)) { diff --git a/050scenario.cc b/050scenario.cc index 791ac38a..4a4c9315 100644 --- a/050scenario.cc +++ b/050scenario.cc @@ -225,7 +225,6 @@ void run_mu_scenario(const scenario& s) { if (!Hide_errors && trace_contains_errors() && !Scenario_testing_scenario) Passed = false; if (not_already_inside_test && Trace_stream) { - if (Save_trace) Trace_stream->save(); delete Trace_stream; Trace_stream = NULL; } @@ -423,7 +422,7 @@ void check_memory(const string& s) { double value = to_double(rhs); if (contains_key(locations_checked, address)) raise << maybe(current_recipe_name()) << "duplicate expectation for location '" << address << "'\n" << end(); - trace("run") << "checking location " << address << end(); + trace(Callstack_depth+1, "run") << "checking location " << address << end(); if (get_or_insert(Memory, address) != value) { if (!Hide_errors) cerr << '\n'; raise << "F - " << maybe(current_recipe_name()) << "expected location '" << address << "' to contain " << no_scientific(value) << " but saw " << no_scientific(get_or_insert(Memory, address)) << '\n' << end(); @@ -469,7 +468,7 @@ void check_type(const string& lhs, istream& in) { } void check_mu_text(int start, const string& literal) { - trace("run") << "checking text length at " << start << end(); + trace(Callstack_depth+1, "run") << "checking text length at " << start << end(); int array_length = static_cast(get_or_insert(Memory, start)); if (array_length != SIZE(literal)) { if (!Hide_errors) cerr << '\n'; @@ -479,7 +478,7 @@ void check_mu_text(int start, const string& literal) { } int curr = start+1; // now skip length for (int i = 0; i < SIZE(literal); ++i) { - trace("run") << "checking location " << curr+i << end(); + trace(Callstack_depth+1, "run") << "checking location " << curr+i << end(); if (get_or_insert(Memory, curr+i) != literal.at(i)) { if (!Hide_errors) cerr << '\n'; raise << "F - " << maybe(current_recipe_name()) << "expected location " << (curr+i) << " to contain " << literal.at(i) << " but saw " << no_scientific(get_or_insert(Memory, curr+i)) << '\n' << end(); @@ -620,16 +619,18 @@ void check_trace(const string& expected) { vector parse_trace(const string& expected) { vector buf = split(expected, "\n"); vector result; + const string separator = ": "; for (int i = 0; i < SIZE(buf); ++i) { buf.at(i) = trim(buf.at(i)); if (buf.at(i).empty()) continue; - int delim = buf.at(i).find(": "); + int delim = buf.at(i).find(separator); if (delim == -1) { raise << maybe(current_recipe_name()) << "lines in 'trace-should-contain' should be of the form