✨ add function call trace info

makefile

@@ -127,12 +127,14 @@ build/nasal_builtin.o: \
 
 build/coroutine.o: \
 	src/nasal.h\
+	src/nasal_type.h\
 	src/nasal_gc.h\
 	src/coroutine.h src/coroutine.cpp | build
 	$(CXX) $(CXXFLAGS) src/coroutine.cpp -o build/coroutine.o
 
 build/bits_lib.o: \
 	src/nasal.h\
+	src/nasal_type.h\
 	src/nasal_gc.h\
 	src/bits_lib.h src/bits_lib.cpp | build
 	$(CXX) $(CXXFLAGS) src/bits_lib.cpp -o build/bits_lib.o
@@ -140,30 +142,35 @@ build/bits_lib.o: \
 
 build/math_lib.o: \
 	src/nasal.h\
+	src/nasal_type.h\
 	src/nasal_gc.h\
 	src/math_lib.h src/math_lib.cpp | build
 	$(CXX) $(CXXFLAGS) src/math_lib.cpp -o build/math_lib.o
 
 build/io_lib.o: \
 	src/nasal.h\
+	src/nasal_type.h\
 	src/nasal_gc.h\
 	src/io_lib.h src/io_lib.cpp | build
 	$(CXX) $(CXXFLAGS) src/io_lib.cpp -o build/io_lib.o
 
 build/dylib_lib.o: \
 	src/nasal.h\
+	src/nasal_type.h\
 	src/nasal_gc.h\
 	src/dylib_lib.h src/dylib_lib.cpp | build
 	$(CXX) $(CXXFLAGS) src/dylib_lib.cpp -o build/dylib_lib.o
 
 build/unix_lib.o: \
 	src/nasal.h\
+	src/nasal_type.h\
 	src/nasal_gc.h\
 	src/unix_lib.h src/unix_lib.cpp | build
 	$(CXX) $(CXXFLAGS) src/unix_lib.cpp -o build/unix_lib.o
 
 build/fg_props.o: \
 	src/nasal.h\
+	src/nasal_type.h\
 	src/nasal_gc.h\
 	src/fg_props.h src/fg_props.cpp | build
 	$(CXX) $(CXXFLAGS) src/fg_props.cpp -o build/fg_props.o

src/nasal_dbg.cpp

@@ -159,7 +159,7 @@ void dbg::step_info() {
 
     begin = (ctx.pc>>3)==0? 0:((ctx.pc>>3)<<3);
     end = (1+(ctx.pc>>3))<<3;
-    codestream::set(cnum, cstr, native.data(), files);
+    codestream::set(const_number, const_string, native_function.data(), files);
     std::clog << "next bytecode:\n";
     for(u32 i = begin; i<end && bytecode[i].op!=op_exit; ++i) {
         std::clog
@@ -168,7 +168,7 @@ void dbg::step_info() {
         << codestream(bytecode[i], i)
         << reset << "\n";
     }
-    stackinfo(10);
+    stack_info(10);
 }
 
 void dbg::interact() {
@@ -200,14 +200,14 @@ void dbg::interact() {
         } else if (res.size()==1) {
             switch(get_cmd_type(res[0])) {
                 case dbg_cmd::cmd_help: help(); break;
-                case dbg_cmd::cmd_backtrace: traceback(); break;
+                case dbg_cmd::cmd_backtrace: trace_back(); break;
                 case dbg_cmd::cmd_continue: return;
                 case dbg_cmd::cmd_list_file: list_file(); break;
-                case dbg_cmd::cmd_global: gstate(); break;
+                case dbg_cmd::cmd_global: global_state(); break;
-                case dbg_cmd::cmd_local: lstate(); break;
+                case dbg_cmd::cmd_local: local_state(); break;
-                case dbg_cmd::cmd_upval: ustate(); break;
+                case dbg_cmd::cmd_upval: upvalue_state(); break;
-                case dbg_cmd::cmd_register: reginfo(); break;
+                case dbg_cmd::cmd_register: register_info(); break;
-                case dbg_cmd::cmd_show_all: detail(); break;
+                case dbg_cmd::cmd_show_all: all_state_detail(); break;
                 case dbg_cmd::cmd_next: next = true; return;
                 case dbg_cmd::cmd_exit: std::exit(0);
                 default: err(); break;

src/nasal_vm.cpp

@@ -11,14 +11,14 @@ void vm::init(
     const std::vector<std::string>& filenames,
     const std::vector<std::string>& argv
 ) {
-    cnum = nums.data();
+    const_number = nums.data();
-    cstr = strs.data();
+    const_string = strs.data();
     bytecode = code.data();
     files = filenames.data();
     global_size = global_symbol.size();
 
     /* set native functions */
-    native = natives;
+    native_function = natives;
 
     /* set context and global */
     if (!is_repl_mode || first_exec_flag) {
@@ -64,7 +64,7 @@ void vm::context_and_global_init() {
     }
 }
 
-void vm::valinfo(var& val) {
+void vm::value_info(var& val) {
     const auto p = reinterpret_cast<u64>(val.val.gcobj);
     switch(val.type) {
         case vm_none: std::clog << "| null |"; break;
@@ -106,10 +106,74 @@ void vm::valinfo(var& val) {
     std::clog << "\n";
 }
 
-void vm::traceback() {
+void vm::function_detail_info(const nas_func& func) {
+    std::clog << "func@0x";
+    std::clog << std::hex << reinterpret_cast<u64>(&func) << std::dec;
+    
+    std::vector<std::string> argument_list = {};
+    argument_list.resize(func.keys.size());
+    for(const auto& key : func.keys) {
+        argument_list[key.second-1] = key.first;
+    }
+
+    std::clog << "(";
+    for(const auto& key : argument_list) {
+        std::clog << key;
+        if (key != argument_list.back()) {
+            std::clog << ", ";
+        }
+    }
+    if (func.dynamic_parameter_index>=0) {
+        std::clog << (argument_list.size()? ", ":"");
+        std::clog << const_string[func.dynamic_parameter_index] << "...";
+    }
+    std::clog << ") ";
+    std::clog << "{entry: 0x" << std::hex << func.entry << std::dec << "}";
+}
+
+void vm::function_call_trace() {
     var* bottom = ctx.stack;
     var* top = ctx.top;
 
+    // generate trace back
+    std::stack<const nas_func*> functions;
+    for(var* i = bottom; i<=top; ++i) {
+        if (i->type==vm_func && i-1>=bottom && (i-1)->type==vm_ret) {
+            functions.push(&i->func());
+        }
+    }
+    if (functions.empty()) {
+        return;
+    }
+
+    std::clog << "\ncall trace " << (ngc.cort? "(coroutine)":"(main)") << "\n";
+    const nas_func* last = nullptr;
+    u32 same = 0;
+    for(auto func = last; !functions.empty(); functions.pop()) {
+        func = functions.top();
+        if (last==func) {
+            ++same;
+            continue;
+        } else if (same) {
+            std::clog << "   --> " << same << " same call(s)\n";
+            same = 0;
+        }
+
+        last = func;
+        std::clog << "  call ";
+        function_detail_info(*func);
+        std::clog << "\n";
+    }
+    if (same) {
+        std::clog << "   --> " << same << " same call(s)\n";
+    }
+}
+
+void vm::trace_back() {
+    var* bottom = ctx.stack;
+    var* top = ctx.top;
+
+    // generate trace back
     std::stack<u32> ret;
     for(var* i = bottom; i<=top; ++i) {
         if (i->type==vm_ret && i->ret()!=0) {
@@ -118,10 +182,8 @@ void vm::traceback() {
     }
     ret.push(ctx.pc); // store the position program crashed
 
-    std::clog << "trace back ("
+    std::clog << "\ntrace back " << (ngc.cort? "(coroutine)":"(main)") << "\n";
-              << (ngc.cort? "coroutine":"main")
+    codestream::set(const_number, const_string, native_function.data(), files);
-              << ")\n";
-    codestream::set(cnum, cstr, native.data(), files);
     for(u32 p = 0, same = 0, prev = 0xffffffff; !ret.empty(); prev = p, ret.pop()) {
         if ((p = ret.top())==prev) {
             ++same;
@@ -132,17 +194,17 @@ void vm::traceback() {
                       << std::setw(6) << std::setfill('0')
                       << prev << std::dec << "     "
                       << same << " same call(s)\n";
-        }
             same = 0;
+        }
         std::clog << "  " << codestream(bytecode[p], p) << "\n";
     }
     // the first called place has no same calls
 }
 
-void vm::stackinfo(const u32 limit = 10) {
+void vm::stack_info(const u32 limit = 10) {
     var* top = ctx.top;
     var* bottom = ctx.stack;
-    std::clog << "stack (0x" << std::hex << reinterpret_cast<u64>(bottom);
+    std::clog << "\nstack (0x" << std::hex << reinterpret_cast<u64>(bottom);
     std::clog << std::dec << ", limit " << limit << ", total ";
     std::clog << (top<bottom? 0:static_cast<i64>(top-bottom+1)) << ")\n";
     for(u32 i = 0; i<limit && top>=bottom; ++i, --top) {
@@ -150,12 +212,12 @@ void vm::stackinfo(const u32 limit = 10) {
                   << std::setw(6) << std::setfill('0')
                   << static_cast<u64>(top-bottom) << std::dec
                   << "    ";
-        valinfo(top[0]);
+        value_info(top[0]);
     }
 }
 
-void vm::reginfo() {
+void vm::register_info() {
-    std::clog << "registers (" << (ngc.cort? "coroutine":"main")
+    std::clog << "\nregisters (" << (ngc.cort? "coroutine":"main")
               << ")\n" << std::hex
               << "  [pc    ]    | pc   | 0x" << ctx.pc << "\n"
               << "  [global]    | addr | 0x"
@@ -169,45 +231,45 @@ void vm::reginfo() {
               << "  [top   ]    | addr | 0x"
               << reinterpret_cast<u64>(ctx.top) << "\n"
               << std::dec;
-    std::clog << "  [funcr ]    "; valinfo(ctx.funcr);
+    std::clog << "  [funcr ]    "; value_info(ctx.funcr);
-    std::clog << "  [upval ]    "; valinfo(ctx.upvalr);
+    std::clog << "  [upval ]    "; value_info(ctx.upvalr);
 }
 
-void vm::gstate() {
+void vm::global_state() {
     if (!global_size || global[0].type==vm_none) {
         return;
     }
-    std::clog << "global (0x" << std::hex
+    std::clog << "\nglobal (0x" << std::hex
               << reinterpret_cast<u64>(global) << ")\n" << std::dec;
     for(usize i = 0; i<global_size; ++i) {
         std::clog << "  0x" << std::hex << std::setw(6)
                   << std::setfill('0') << i << std::dec
                   << "    ";
-        valinfo(global[i]);
+        value_info(global[i]);
     }
 }
 
-void vm::lstate() {
+void vm::local_state() {
     if (!ctx.localr || !ctx.funcr.func().local_size) {
         return;
     }
     const u32 lsize = ctx.funcr.func().local_size;
-    std::clog << "local (0x" << std::hex << reinterpret_cast<u64>(ctx.localr)
+    std::clog << "\nlocal (0x" << std::hex << reinterpret_cast<u64>(ctx.localr)
               << " <+" << static_cast<u64>(ctx.localr-ctx.stack)
               << ">)\n" << std::dec;
     for(u32 i = 0; i<lsize; ++i) {
         std::clog << "  0x" << std::hex << std::setw(6)
                   << std::setfill('0') << i << std::dec
                   << "    ";
-        valinfo(ctx.localr[i]);
+        value_info(ctx.localr[i]);
     }
 }
 
-void vm::ustate() {
+void vm::upvalue_state() {
     if (ctx.funcr.type==vm_nil || ctx.funcr.func().upval.empty()) {
         return;
     }
-    std::clog << "upvalue\n";
+    std::clog << "\nupvalue\n";
     auto& upval = ctx.funcr.func().upval;
     for(u32 i = 0; i<upval.size(); ++i) {
         std::clog << "  -> upval[" << i << "]:\n";
@@ -216,42 +278,77 @@ void vm::ustate() {
             std::clog << "     0x" << std::hex << std::setw(6)
                       << std::setfill('0') << j << std::dec
                       << " ";
-            valinfo(uv[j]);
+            value_info(uv[j]);
         }
     }
 }
 
-void vm::detail() {
+void vm::all_state_detail() {
-    reginfo();
+    register_info();
-    gstate();
+    global_state();
-    lstate();
+    local_state();
-    ustate();
+    upvalue_state();
 }
 
 std::string vm::report_lack_arguments(u32 argc, const nas_func& func) const {
-    auto result = std::string("lack argument(s): ");
+    auto result = std::string("lack argument(s) when calling function:\n  func(");
     std::vector<std::string> argument_list = {};
     argument_list.resize(func.keys.size());
     for(const auto& i : func.keys) {
         argument_list[i.second-1] = i.first;
     }
-    for(u32 i = argc; i<argument_list.size(); ++i) {
+    for(u32 i = 0; i<argument_list.size(); ++i) {
         result += argument_list[i];
+        if (i<argc) {
+            result += "[get]";
+        }
         if (i!=argument_list.size()-1) {
             result += ", ";
         }
     }
-    return result;
+    if (func.dynamic_parameter_index>=0) {
+        result += argument_list.size()? ", ":"";
+        result += const_string[func.dynamic_parameter_index] + "[dynamic]";
+    }
+    result += ") ";
+    std::stringstream out;
+    out << "{entry: 0x" << std::hex << func.entry << std::dec << "}";
+    out << " @ 0x" << std::hex << reinterpret_cast<u64>(&func) << std::dec;
+    return result + out.str();
+}
+
+std::string vm::report_special_call_lack_arguments(
+    var* local, const nas_func& func) const {
+    auto result = std::string("lack argument(s) when calling function:\n  func(");
+    std::vector<std::string> argument_list = {};
+    argument_list.resize(func.keys.size());
+    for(const auto& i : func.keys) {
+        argument_list[i.second-1] = i.first;
+    }
+    for(const auto& key : argument_list) {
+        if (local[func.keys.at(key)].type==vm_none) {
+            result += key + ", ";
+        } else {
+            result += key + "[get], ";
+        }
+    }
+    result = result.substr(0, result.length()-2);
+    result += ") ";
+    std::stringstream out;
+    out << "{entry: 0x" << std::hex << func.entry << std::dec << "}";
+    out << " @ 0x" << std::hex << reinterpret_cast<u64>(&func) << std::dec;
+    return result + out.str();
 }
 
 void vm::die(const std::string& str) {
     std::cerr << "[vm] error: " << str << "\n";
-    traceback();
+    function_call_trace();
-    stackinfo();
+    trace_back();
+    stack_info();
 
     // show verbose crash info
     if (verbose) {
-        detail();
+        all_state_detail();
     }
 
     if (!ngc.cort) {

src/nasal_vm.h

@@ -2,6 +2,8 @@
 
 #include <iomanip>
 #include <stack>
+#include <cstring>
+#include <sstream>
 
 #include "nasal_import.h"
 #include "nasal_gc.h"
@@ -22,10 +24,10 @@ protected:
     context ctx;
 
     /* constants */
-    const f64* cnum = nullptr; // constant numbers
+    const f64* const_number = nullptr; // constant numbers
-    const std::string* cstr = nullptr; // constant symbols and strings
+    const std::string* const_string = nullptr; // constant symbols and strings
     std::vector<u32> imm; // immediate number table
-    std::vector<nasal_builtin_table> native;
+    std::vector<nasal_builtin_table> native_function;
     
     /* garbage collector */
     gc ngc;
@@ -57,15 +59,18 @@ protected:
 
     /* debug functions */
     bool verbose = false;
-    void valinfo(var&);
+    void value_info(var&);
-    void traceback();
+    void function_detail_info(const nas_func&);
-    void stackinfo(const u32);
+    void function_call_trace();
-    void reginfo();
+    void trace_back();
-    void gstate();
+    void stack_info(const u32);
-    void lstate();
+    void register_info();
-    void ustate();
+    void global_state();
-    void detail();
+    void local_state();
+    void upvalue_state();
+    void all_state_detail();
     std::string report_lack_arguments(u32, const nas_func&) const;
+    std::string report_special_call_lack_arguments(var*, const nas_func&) const;
     void die(const std::string&);
 
     /* vm calculation functions*/
@@ -222,7 +227,7 @@ inline void vm::o_loadu() {
 }
 
 inline void vm::o_pnum() {
-    (++ctx.top)[0] = var::num(cnum[imm[ctx.pc]]);
+    (++ctx.top)[0] = var::num(const_number[imm[ctx.pc]]);
 }
 
 inline void vm::o_pnil() {
@@ -269,14 +274,14 @@ inline void vm::o_newf() {
 }
 
 inline void vm::o_happ() {
-    ctx.top[-1].hash().elems[cstr[imm[ctx.pc]]] = ctx.top[0];
+    ctx.top[-1].hash().elems[const_string[imm[ctx.pc]]] = ctx.top[0];
     --ctx.top;
 }
 
 inline void vm::o_para() {
     auto& func = ctx.top[0].func();
     // func->size has 1 place reserved for "me"
-    func.keys[cstr[imm[ctx.pc]]] = func.parameter_size;
+    func.keys[const_string[imm[ctx.pc]]] = func.parameter_size;
     func.local[func.parameter_size++] = var::none();
 }
 
@@ -284,7 +289,7 @@ inline void vm::o_deft() {
     var val = ctx.top[0];
     auto& func = (--ctx.top)[0].func();
     // func->size has 1 place reserved for "me"
-    func.keys[cstr[imm[ctx.pc]]] = func.parameter_size;
+    func.keys[const_string[imm[ctx.pc]]] = func.parameter_size;
     func.local[func.parameter_size++] = val;
 }
 
@@ -370,14 +375,14 @@ inline void vm::o_lnk() {
 }
 
 #define op_calc_const(type)\
-    ctx.top[0] = var::num(ctx.top[0].tonum() type cnum[imm[ctx.pc]]);
+    ctx.top[0] = var::num(ctx.top[0].tonum() type const_number[imm[ctx.pc]]);
 
 inline void vm::o_addc() {op_calc_const(+);}
 inline void vm::o_subc() {op_calc_const(-);}
 inline void vm::o_mulc() {op_calc_const(*);}
 inline void vm::o_divc() {op_calc_const(/);}
 inline void vm::o_lnkc() {
-    ctx.top[0] = ngc.newstr(ctx.top[0].tostr()+cstr[imm[ctx.pc]]);
+    ctx.top[0] = ngc.newstr(ctx.top[0].tostr()+const_string[imm[ctx.pc]]);
 }
 
 // top[0] stores the value of memr[0], to avoid being garbage-collected
@@ -435,7 +440,9 @@ inline void vm::o_bxoreq() {
 // like this: func{a+=1;}(); the result of 'a+1' will no be used later, imm[pc]>>31=1
 // but if b+=a+=1; the result of 'a+1' will be used later, imm[pc]>>31=0
 #define op_calc_eq_const(type)\
-    ctx.top[0] = ctx.memr[0] = var::num(ctx.memr[0].tonum() type cnum[imm[ctx.pc]]);\
+    ctx.top[0] = ctx.memr[0] = var::num(\
+        ctx.memr[0].tonum() type const_number[imm[ctx.pc]]\
+    );\
     ctx.memr = nullptr;
 
 inline void vm::o_addeqc() {op_calc_eq_const(+);}
@@ -443,12 +450,16 @@ inline void vm::o_subeqc() {op_calc_eq_const(-);}
 inline void vm::o_muleqc() {op_calc_eq_const(*);}
 inline void vm::o_diveqc() {op_calc_eq_const(/);}
 inline void vm::o_lnkeqc() {
-    ctx.top[0] = ctx.memr[0] = ngc.newstr(ctx.memr[0].tostr()+cstr[imm[ctx.pc]]);
+    ctx.top[0] = ctx.memr[0] = ngc.newstr(
+        ctx.memr[0].tostr()+const_string[imm[ctx.pc]]
+    );
     ctx.memr = nullptr;
 }
 
 #define op_calc_eq_const_and_pop(type)\
-    ctx.top[0] = ctx.memr[0] = var::num(ctx.memr[0].tonum() type cnum[imm[ctx.pc]]);\
+    ctx.top[0] = ctx.memr[0] = var::num(\
+        ctx.memr[0].tonum() type const_number[imm[ctx.pc]]\
+    );\
     ctx.memr = nullptr;\
     --ctx.top;
 
@@ -458,7 +469,7 @@ inline void vm::o_mulecp() {op_calc_eq_const_and_pop(*);}
 inline void vm::o_divecp() {op_calc_eq_const_and_pop(/);}
 inline void vm::o_lnkecp() {
     ctx.top[0] = ctx.memr[0] = ngc.newstr(
-        ctx.memr[0].tostr()+cstr[imm[ctx.pc]]
+        ctx.memr[0].tostr()+const_string[imm[ctx.pc]]
     );
     ctx.memr = nullptr;
     --ctx.top;
@@ -515,7 +526,7 @@ inline void vm::o_grt() {op_cmp(>);}
 inline void vm::o_geq() {op_cmp(>=);}
 
 #define op_cmp_const(type)\
-    ctx.top[0] = (ctx.top[0].tonum() type cnum[imm[ctx.pc]])? one:zero;
+    ctx.top[0] = (ctx.top[0].tonum() type const_number[imm[ctx.pc]])? one:zero;
 
 inline void vm::o_lessc() {op_cmp_const(<);}
 inline void vm::o_leqc() {op_cmp_const(<=);}
@@ -656,7 +667,7 @@ inline void vm::o_callh() {
         die("must call a hash");
         return;
     }
-    const auto& str = cstr[imm[ctx.pc]];
+    const auto& str = const_string[imm[ctx.pc]];
     if (val.type==vm_hash) {
         ctx.top[0] = val.hash().get_val(str);
     } else {
@@ -761,7 +772,7 @@ inline void vm::o_callfh() {
     // dynamic parameter is not allowed in this kind of function call
     if (func.dynamic_parameter_index>=0) {
         die("special call cannot use dynamic argument \"" +
-            cstr[func.dynamic_parameter_index] + "\""
+            const_string[func.dynamic_parameter_index] + "\""
         );
         return;
     }
@@ -782,15 +793,7 @@ inline void vm::o_callfh() {
         }
     }
     if (lack_arguments_flag) {
-        auto info = std::string("lack argument(s): ");
+        die(report_special_call_lack_arguments(local, func));
-        for(const auto& i : func.keys) {
-            const auto& key = i.first;
-            if (local[i.second].type==vm_none) {
-                info += key + ", ";
-            }
-        }
-        info = info.substr(0, info.length()-2);
-        die(info);
         return;
     }
 
@@ -809,7 +812,7 @@ inline void vm::o_callb() {
 
     // if running a native function about coroutine
     // (top) will be set to another context.top, instead of main_context.top
-    var tmp = (*native[imm[ctx.pc]].func)(ctx.localr, ngc);
+    var tmp = (*native_function[imm[ctx.pc]].func)(ctx.localr, ngc);
 
     // so we use tmp variable to store this return value
     // and set it to top[0] later
@@ -949,7 +952,7 @@ inline void vm::o_mcallh() {
         die("must call a hash");
         return;
     }
-    const auto& str = cstr[imm[ctx.pc]];
+    const auto& str = const_string[imm[ctx.pc]];
     if (hash.type==vm_map) {
         ctx.memr = hash.map().get_mem(str);
         if (!ctx.memr) {