From 044ccb4bc6597723cae2d5ac7a9e2c1fb3d62758 Mon Sep 17 00:00:00 2001
From: ValKmjolnir <lhk101lhk101@qq.com>
Date: Sun, 6 Aug 2023 20:02:12 +0800
Subject: [PATCH] :sparkles: add profiling tools in debug mode

---
 src/main.cpp          |  51 ++++++-----
 src/nasal_codegen.cpp |  13 +--
 src/nasal_codegen.h   |   1 +
 src/nasal_dbg.cpp     | 197 +++++++++++++++++++++++++-----------------
 src/nasal_dbg.h       |  88 ++++++++++++++++++-
 src/nasal_err.h       |   5 +-
 src/nasal_import.h    |   6 +-
 src/nasal_vm.cpp      |   2 +-
 8 files changed, 250 insertions(+), 113 deletions(-)

diff --git a/src/main.cpp b/src/main.cpp
index a29b583..29c8864 100644
--- a/src/main.cpp
+++ b/src/main.cpp
@@ -16,14 +16,16 @@
 #include <thread>
 #include <cstdlib>
 
-const u32 VM_RAW_AST = 1;
-const u32 VM_AST     = 1<<1;
-const u32 VM_CODE    = 1<<2;
-const u32 VM_TIME    = 1<<3;
-const u32 VM_EXEC    = 1<<4;
-const u32 VM_DETAIL  = 1<<5;
-const u32 VM_DEBUG   = 1<<6;
-const u32 VM_SYMINFO = 1<<7;
+const u32 VM_RAW_AST  = 1;
+const u32 VM_AST      = 1<<1;
+const u32 VM_CODE     = 1<<2;
+const u32 VM_TIME     = 1<<3;
+const u32 VM_EXEC     = 1<<4;
+const u32 VM_DETAIL   = 1<<5;
+const u32 VM_DEBUG    = 1<<6;
+const u32 VM_SYMINFO  = 1<<7;
+const u32 VM_PROFILE  = 1<<8;
+const u32 VM_PROF_ALL = 1<<9;
 
 std::ostream& help(std::ostream& out) {
     out
@@ -36,22 +38,25 @@ std::ostream& help(std::ostream& out) {
 #endif
     << "\nnasal <option>\n"
     << "option:\n"
-    << "   -h,   --help    | get help.\n"
-    << "   -v,   --version | get version.\n"
+    << "   -h,   --help     | get help.\n"
+    << "   -v,   --version  | get version.\n"
     << "\nnasal [option] <file> [argv]\n"
     << "option:\n"
-    << "   -a,   --ast     | view ast after link/optimize process.\n"
-    << "         --raw-ast | view ast without after-processing.\n"
-    << "   -c,   --code    | view generated bytecode.\n"
-    << "   -s,   --symbol  | show analysed symbol info.\n"
-    << "   -e,   --exec    | execute directly.\n"
-    << "   -t,   --time    | show execute time.\n"
-    << "   -d,   --detail  | get detail info.\n"
-    << "   -dbg, --debug   | debug mode.\n"
+    << "   -a,   --ast      | view ast after link/optimize process.\n"
+    << "         --raw-ast  | view ast without after-processing.\n"
+    << "   -c,   --code     | view generated bytecode.\n"
+    << "   -s,   --symbol   | show analysed symbol info.\n"
+    << "   -e,   --exec     | execute directly.\n"
+    << "   -t,   --time     | show execute time.\n"
+    << "   -d,   --detail   | get detail info.\n"
+    << "   -dbg, --debug    | debug mode.\n"
+    << "         --prof     | show profiling result, available under debug mode.\n"
+    << "         --prof-all | show profiling result of all files,"
+    << "available under debug mode.\n"
     << "file:\n"
-    << "   <filename>      | execute file.\n"
+    << "   <filename>       | execute file.\n"
     << "argv:\n"
-    << "   <args>          | cmd arguments used in program.\n"
+    << "   <args>           | cmd arguments used in program.\n"
     << "\n";
     return out;
 }
@@ -145,7 +150,7 @@ void execute(
     // run
     auto start = clk::now();
     if (cmd&VM_DEBUG) {
-        dbg().run(gen, ld, argv);
+        dbg().run(gen, ld, argv, cmd&VM_PROFILE, cmd&VM_PROF_ALL);
     } else if (cmd&VM_TIME || cmd&VM_EXEC) {
         ctx.run(gen, ld, argv, cmd&VM_DETAIL);
     }
@@ -195,7 +200,9 @@ i32 main(i32 argc, const char* argv[]) {
         {"--detail", VM_DETAIL|VM_EXEC},
         {"-d", VM_DETAIL|VM_EXEC},
         {"--debug", VM_DEBUG},
-        {"-dbg", VM_DEBUG}
+        {"-dbg", VM_DEBUG},
+        {"--prof", VM_PROFILE},
+        {"--prof-all", VM_PROF_ALL}
     };
     u32 cmd = 0;
     std::string filename = "";
diff --git a/src/nasal_codegen.cpp b/src/nasal_codegen.cpp
index fdad27a..e55086e 100644
--- a/src/nasal_codegen.cpp
+++ b/src/nasal_codegen.cpp
@@ -1,5 +1,12 @@
 #include "nasal_codegen.h"
 
+void codegen::init_file_map(const std::vector<std::string>& file_list) {
+    file_map = {};
+    for(usize i = 0; i<file_list.size(); ++i) {
+        file_map.insert({file_list[i], i});
+    }
+}
+
 void codegen::load_native_function_table(nasal_builtin_table* table) {
     for(usize i = 0; table[i].func; ++i) {
         if (native_function_mapper.count(table[i].name)) {
@@ -1133,11 +1140,7 @@ void codegen::ret_gen(return_expr* node) {
 
 const error& codegen::compile(parse& parse, linker& import, bool repl) {
     init_native_function();
-    const auto& file = import.filelist();
-    file_map = {};
-    for(usize i = 0; i<file.size(); ++i) {
-        file_map[file[i]] = i;
-    }
+    init_file_map(import.get_file_list());
 
     in_loop_level.push_back(0);
 
diff --git a/src/nasal_codegen.h b/src/nasal_codegen.h
index 9820e4e..fdf10bc 100644
--- a/src/nasal_codegen.h
+++ b/src/nasal_codegen.h
@@ -31,6 +31,7 @@ private:
 
     // file mapper for file -> index
     std::unordered_map<std::string, usize> file_map;
+    void init_file_map(const std::vector<std::string>&);
 
     // used for generate pop in return expression
     std::vector<u32> in_loop_level;
diff --git a/src/nasal_dbg.cpp b/src/nasal_dbg.cpp
index cd50eff..266633e 100644
--- a/src/nasal_dbg.cpp
+++ b/src/nasal_dbg.cpp
@@ -1,5 +1,94 @@
 #include "nasal_dbg.h"
 
+void debug_prof_data::init_counter() {
+    for(usize i = 0; i<debug_prof_data::operand_size; ++i) {
+        operand_counter[i] = 0;
+    }
+}
+
+void debug_prof_data::load_file_line_counter(
+    const std::vector<std::string>& file_list) {
+    file_name_list = file_list;
+    file_line_counter = {};
+    file_contents = {};
+    flstream fs;
+    for(usize i =0; i<file_list.size(); ++i) {
+        fs.load(file_list[i]);
+        file_contents.push_back(fs.file_content());
+        file_line_counter.push_back({});
+        file_line_counter.back().resize(fs.size(), 0);
+    }
+}
+
+void debug_prof_data::init(const std::vector<std::string>& file_list) {
+    init_counter();
+    load_file_line_counter(file_list);
+}
+
+void debug_prof_data::dump_counter() const {
+    typedef std::pair<u32, u64> op_count;
+    std::vector<op_count> opcall;
+    u64 total = 0;
+    for(usize i = 0; i<debug_prof_data::operand_size; ++i) {
+        total += operand_counter[i];
+        opcall.push_back({i, operand_counter[i]});
+    }
+    std::sort(opcall.begin(), opcall.end(),
+        [](const op_count& a, const op_count& b) {
+            return a.second>b.second;
+        }
+    );
+    std::clog << "\noperands call info (<1% ignored)\n";
+    for(const auto& i : opcall) {
+        u64 rate = i.second*100/total;
+        if (!rate) {
+            break;
+        }
+        std::clog << " " << opname[i.first] << " : ";
+        std::clog << i.second << " (" << rate << "%)\n";
+    }
+    std::clog << " total  : " << total << '\n';
+}
+
+void debug_prof_data::dump_code_line_counter(std::ostream& os) const {
+    u64 max_call_time = 0;
+    for(const auto& context : file_line_counter) {
+        for(const auto& count : context) {
+            max_call_time = count>max_call_time? count:max_call_time;
+        }
+    }
+    auto pad_length = std::to_string(max_call_time).length();
+    for(usize i = 0; i<file_name_list.size(); ++i) {
+        os << "\ncode profiling data of " << file_name_list[i] << ":\n";
+        const auto& context = file_contents[i];
+        const auto& counter = file_line_counter[i];
+        for(usize j = 0; j<context.size(); ++j) {
+            os << " " << std::right << std::setw(pad_length);
+            os << std::setfill(' ');
+            os << (counter[j]==0? "":std::to_string(counter[j]));
+            os << " " << context[j] << "\n";
+        }
+    }
+}
+
+void debug_prof_data::dump_this_file_line_counter(std::ostream& os) const {
+    u64 max_call_time = 0;
+    for(const auto& count : file_line_counter[0]) {
+        max_call_time = count>max_call_time? count:max_call_time;
+    }
+    auto pad_length = std::to_string(max_call_time).length();
+
+    os << "\ncode profiling data of " << file_name_list[0] << ":\n";
+    const auto& context = file_contents[0];
+    const auto& counter = file_line_counter[0];
+    for(usize i = 0; i<context.size(); ++i) {
+        os << " " << std::right << std::setw(pad_length);
+        os << std::setfill(' ');
+        os << (counter[i]==0? "":std::to_string(counter[i]));
+        os << " " << context[i] << "\n";
+    }
+}
+
 std::vector<std::string> dbg::parse(const std::string& cmd) {
     std::vector<std::string> res;
     usize last = 0, pos = cmd.find(" ", 0);
@@ -55,29 +144,6 @@ void dbg::list_file() const {
     }
 }
 
-void dbg::call_sort(const u64* arr) const {
-    typedef std::pair<u32,u64> op;
-    std::vector<op> opcall;
-    u64 total = 0;
-    for(u32 i = 0; i<op_ret+1; ++i) {
-        total += arr[i];
-        opcall.push_back({i, arr[i]});
-    }
-    std::sort(opcall.begin(), opcall.end(),
-        [](const op& a, const op& b) {return a.second>b.second;}
-    );
-    std::clog << "\noperands call info (<1% ignored)\n";
-    for(auto& i : opcall) {
-        u64 rate = i.second*100/total;
-        if (!rate) {
-            break;
-        }
-        std::clog << " " << opname[i.first] << " : ";
-        std::clog << i.second << " (" << rate << "%)\n";
-    }
-    std::clog << " total  : " << total << '\n';
-}
-
 void dbg::step_info() {
     u32 line = bytecode[ctx.pc].line==0? 0:bytecode[ctx.pc].line-1;
     u32 begin = (line>>3)==0? 0:((line>>3)<<3);
@@ -108,6 +174,11 @@ void dbg::interact() {
     if (bytecode[ctx.pc].op==op_exit) {
         return;
     }
+
+    // do not need interact while doing profiling
+    if (do_profiling) {
+        return;
+    }
     
     if ((bytecode[ctx.pc].fidx!=bk_fidx ||
         bytecode[ctx.pc].line!=bk_line) && // break point
@@ -161,75 +232,45 @@ void dbg::interact() {
 void dbg::run(
     const codegen& gen,
     const linker& linker,
-    const std::vector<std::string>& argv) {
+    const std::vector<std::string>& argv,
+    bool profile,
+    bool show_all_prof_result) {
     verbose = true;
-    fsize = linker.filelist().size();
+    do_profiling = profile || show_all_prof_result;
+
+    const auto& file_list = linker.get_file_list();
+    fsize = file_list.size();
     init(gen.strs(), gen.nums(), gen.natives(),
-         gen.codes(), gen.globals(), linker.filelist(), argv);
-    u64 count[op_ret+1] = {0};
-    typedef void (dbg::*nafunc)();
-    const nafunc oprs[] = {
-        nullptr,        &dbg::o_intg,
-        &dbg::o_intl,   &dbg::o_loadg,
-        &dbg::o_loadl,  &dbg::o_loadu,
-        &dbg::o_pnum,   &dbg::o_pnil,
-        &dbg::o_pstr,   &dbg::o_newv,
-        &dbg::o_newh,   &dbg::o_newf,
-        &dbg::o_happ,   &dbg::o_para,
-        &dbg::o_deft,   &dbg::o_dyn,
-        &dbg::o_lnot,   &dbg::o_usub,
-        &dbg::o_bnot,   &dbg::o_btor,
-        &dbg::o_btxor,  &dbg::o_btand,
-        &dbg::o_add,    &dbg::o_sub,
-        &dbg::o_mul,    &dbg::o_div,
-        &dbg::o_lnk,    &dbg::o_addc,
-        &dbg::o_subc,   &dbg::o_mulc,
-        &dbg::o_divc,   &dbg::o_lnkc,
-        &dbg::o_addeq,  &dbg::o_subeq,
-        &dbg::o_muleq,  &dbg::o_diveq,
-        &dbg::o_lnkeq,  &dbg::o_bandeq,
-        &dbg::o_boreq,  &dbg::o_bxoreq,
-        &dbg::o_addeqc, &dbg::o_subeqc,
-        &dbg::o_muleqc, &dbg::o_diveqc,
-        &dbg::o_lnkeqc, &dbg::o_addecp,
-        &dbg::o_subecp, &dbg::o_mulecp,
-        &dbg::o_divecp, &dbg::o_lnkecp,
-        &dbg::o_meq,    &dbg::o_eq,
-        &dbg::o_neq,    &dbg::o_less,
-        &dbg::o_leq,    &dbg::o_grt,
-        &dbg::o_geq,    &dbg::o_lessc,
-        &dbg::o_leqc,   &dbg::o_grtc,
-        &dbg::o_geqc,   &dbg::o_pop,
-        &dbg::o_jmp,    &dbg::o_jt,
-        &dbg::o_jf,     &dbg::o_cnt,
-        &dbg::o_findex, &dbg::o_feach,
-        &dbg::o_callg,  &dbg::o_calll,
-        &dbg::o_upval,  &dbg::o_callv,
-        &dbg::o_callvi, &dbg::o_callh,
-        &dbg::o_callfv, &dbg::o_callfh,
-        &dbg::o_callb,  &dbg::o_slcbeg,
-        &dbg::o_slcend, &dbg::o_slc,
-        &dbg::o_slc2,   &dbg::o_mcallg,
-        &dbg::o_mcalll, &dbg::o_mupval,
-        &dbg::o_mcallv, &dbg::o_mcallh,
-        &dbg::o_ret
-    };
+         gen.codes(), gen.globals(),
+         file_list, argv);
+    data.init(file_list);
+
     std::vector<u32> code;
+    std::vector<u16> code_file_index;
+    std::vector<u32> code_line;
     for(auto& i : gen.codes()) {
         code.push_back(i.op);
+        code_file_index.push_back(i.fidx);
+        code_line.push_back(i.line);
         imm.push_back(i.num);
     }
-    while(oprs[code[ctx.pc]]) {
+    while(operand_function[code[ctx.pc]]) {
         interact();
-        ++count[code[ctx.pc]];
-        (this->*oprs[code[ctx.pc]])();
+        data.add_operand_counter(code[ctx.pc]);
+        data.add_code_line_counter(code_file_index[ctx.pc], code_line[ctx.pc]);
+        (this->*operand_function[code[ctx.pc]])();
         if (ctx.top>=ctx.canary) {
             die("stack overflow");
         }
         ++ctx.pc;
     }
 
-    call_sort(count);
+    data.dump_counter();
+    if (do_profiling) {
+        show_all_prof_result?
+            data.dump_code_line_counter(std::clog):
+            data.dump_this_file_line_counter(std::clog);
+    }
     ngc.info();
     ngc.clear();
     imm.clear();
diff --git a/src/nasal_dbg.h b/src/nasal_dbg.h
index 7a5f700..7f466e4 100644
--- a/src/nasal_dbg.h
+++ b/src/nasal_dbg.h
@@ -9,7 +9,82 @@
 #include <algorithm>
 #include <unordered_map>
 
+class debug_prof_data {
+private:
+    static const usize operand_size = op_code_type::op_ret + 1;
+    u64 operand_counter[operand_size];
+    std::vector<std::string> file_name_list;
+    std::vector<std::vector<u64>> file_line_counter;
+    std::vector<std::vector<std::string>> file_contents;
+
+private:
+    void init_counter();
+    void load_file_line_counter(const std::vector<std::string>&);
+
+public:
+    void init(const std::vector<std::string>&);
+    void dump_counter() const;
+    void dump_code_line_counter(std::ostream&) const;
+    void dump_this_file_line_counter(std::ostream&) const;
+    void add_operand_counter(usize index) {
+        operand_counter[index] += index<operand_size? 1:0;
+    }
+    void add_code_line_counter(usize fidx, usize line) {
+        auto& vec = file_line_counter[fidx];
+        vec[line==0? line: line-1]++;
+    }
+};
+
 class dbg:public vm {
+private:
+    typedef void (dbg::*nasal_vm_func)();
+    const nasal_vm_func operand_function[op_ret + 1] = {
+        nullptr,        &dbg::o_intg,
+        &dbg::o_intl,   &dbg::o_loadg,
+        &dbg::o_loadl,  &dbg::o_loadu,
+        &dbg::o_pnum,   &dbg::o_pnil,
+        &dbg::o_pstr,   &dbg::o_newv,
+        &dbg::o_newh,   &dbg::o_newf,
+        &dbg::o_happ,   &dbg::o_para,
+        &dbg::o_deft,   &dbg::o_dyn,
+        &dbg::o_lnot,   &dbg::o_usub,
+        &dbg::o_bnot,   &dbg::o_btor,
+        &dbg::o_btxor,  &dbg::o_btand,
+        &dbg::o_add,    &dbg::o_sub,
+        &dbg::o_mul,    &dbg::o_div,
+        &dbg::o_lnk,    &dbg::o_addc,
+        &dbg::o_subc,   &dbg::o_mulc,
+        &dbg::o_divc,   &dbg::o_lnkc,
+        &dbg::o_addeq,  &dbg::o_subeq,
+        &dbg::o_muleq,  &dbg::o_diveq,
+        &dbg::o_lnkeq,  &dbg::o_bandeq,
+        &dbg::o_boreq,  &dbg::o_bxoreq,
+        &dbg::o_addeqc, &dbg::o_subeqc,
+        &dbg::o_muleqc, &dbg::o_diveqc,
+        &dbg::o_lnkeqc, &dbg::o_addecp,
+        &dbg::o_subecp, &dbg::o_mulecp,
+        &dbg::o_divecp, &dbg::o_lnkecp,
+        &dbg::o_meq,    &dbg::o_eq,
+        &dbg::o_neq,    &dbg::o_less,
+        &dbg::o_leq,    &dbg::o_grt,
+        &dbg::o_geq,    &dbg::o_lessc,
+        &dbg::o_leqc,   &dbg::o_grtc,
+        &dbg::o_geqc,   &dbg::o_pop,
+        &dbg::o_jmp,    &dbg::o_jt,
+        &dbg::o_jf,     &dbg::o_cnt,
+        &dbg::o_findex, &dbg::o_feach,
+        &dbg::o_callg,  &dbg::o_calll,
+        &dbg::o_upval,  &dbg::o_callv,
+        &dbg::o_callvi, &dbg::o_callh,
+        &dbg::o_callfv, &dbg::o_callfh,
+        &dbg::o_callb,  &dbg::o_slcbeg,
+        &dbg::o_slcend, &dbg::o_slc,
+        &dbg::o_slc2,   &dbg::o_mcallg,
+        &dbg::o_mcalll, &dbg::o_mupval,
+        &dbg::o_mcallv, &dbg::o_mcallh,
+        &dbg::o_ret
+    };
+
 private:
     enum class dbg_cmd {
         cmd_error,
@@ -66,20 +141,27 @@ private:
     u32 bk_line;
     error src;
 
+    debug_prof_data data;
+    bool do_profiling;
+
     std::vector<std::string> parse(const std::string&);
     u16 file_index(const std::string&) const;
     void err();
     void help();
     void list_file() const;
-    void call_sort(const u64*) const;
     void step_info();
     void interact();
 
 public:
-    dbg(): next(false), fsize(0), bk_fidx(0), bk_line(0) {}
+    dbg():
+        next(false), fsize(0),
+        bk_fidx(0), bk_line(0),
+        do_profiling(false) {}
     void run(
         const codegen&,
         const linker&,
-        const std::vector<std::string>&
+        const std::vector<std::string>&,
+        bool,
+        bool
     );
 };
diff --git a/src/nasal_err.h b/src/nasal_err.h
index 897d9b5..277b059 100644
--- a/src/nasal_err.h
+++ b/src/nasal_err.h
@@ -27,11 +27,13 @@ class flstream {
 protected:
     std::string file;
     std::vector<std::string> res;
+
 public:
     flstream():file("") {}
     void load(const std::string&);
     const std::string& operator[](usize n) const {return res[n];}
-    const std::string& name() const {return file;}
+    const auto& name() const {return file;}
+    const auto& file_content() const {return res;}
     usize size() const {return res.size();}
 };
 
@@ -49,6 +51,7 @@ private:
         }
         return tmp;
     }
+
 public:
     error():cnt(0) {}
     void fatal(const std::string&, const std::string&);
diff --git a/src/nasal_import.h b/src/nasal_import.h
index 2be93ad..e50161f 100644
--- a/src/nasal_import.h
+++ b/src/nasal_import.h
@@ -49,7 +49,7 @@ private:
 public:
     linker();
     const error& link(parse&, const std::string&, bool);
-    const std::vector<std::string>& filelist() const {return files;}
-    const std::string& get_this_file() const {return this_file;}
-    const std::string& get_lib_path() const {return lib_path;}
+    const auto& get_file_list() const {return files;}
+    const auto& get_this_file() const {return this_file;}
+    const auto& get_lib_path() const {return lib_path;}
 };
diff --git a/src/nasal_vm.cpp b/src/nasal_vm.cpp
index 7ac75e4..6249aec 100644
--- a/src/nasal_vm.cpp
+++ b/src/nasal_vm.cpp
@@ -235,7 +235,7 @@ void vm::run(
     const bool detail) {
     verbose = detail;
     init(gen.strs(), gen.nums(), gen.natives(),
-         gen.codes(), gen.globals(), linker.filelist(), argv);
+         gen.codes(), gen.globals(), linker.get_file_list(), argv);
 #ifndef _MSC_VER
     // using labels as values/computed goto
     const void* oprs[] = {