🔥 fuck mac

CMakeLists.txt

@@ -39,6 +39,7 @@ set(NASAL_OBJECT_SOURCE_FILE
     ${CMAKE_SOURCE_DIR}/src/natives/unix_lib.cpp
     ${CMAKE_SOURCE_DIR}/src/repl/repl.cpp
     ${CMAKE_SOURCE_DIR}/src/util/fs.cpp
+    ${CMAKE_SOURCE_DIR}/src/util/gc_stat.cpp
     ${CMAKE_SOURCE_DIR}/src/util/util.cpp
     ${CMAKE_SOURCE_DIR}/src/ast_dumper.cpp
     ${CMAKE_SOURCE_DIR}/src/ast_format.cpp
@@ -97,6 +98,7 @@ set(CMAKE_LIBRARY_OUTPUT_DIRECTORY ${CMAKE_SOURCE_DIR}/module)
 
 set(MODULE_USED_OBJECT_SOURCE_FILE
     ${CMAKE_SOURCE_DIR}/src/util/util.cpp
+    ${CMAKE_SOURCE_DIR}/src/util/gc_stat.cpp
     ${CMAKE_SOURCE_DIR}/src/util/fs.cpp
     ${CMAKE_SOURCE_DIR}/src/nasal_type.cpp
     ${CMAKE_SOURCE_DIR}/src/nasal_gc.cpp)

src/nasal_codegen.cpp

@@ -1436,6 +1436,7 @@ void codegen::print(std::ostream& out) {
     codestream::set(
         const_number_table.data(),
         const_string_table.data(),
+        global,
         native_function.data()
     );
 

src/nasal_codegen.h

@@ -161,11 +161,11 @@ private:
     void ret_gen(return_expr*);
 
 public:
-    const auto& strs() const {return const_string_table;}
-    const auto& nums() const {return const_number_table;}
-    const auto& natives() const {return native_function;}
-    const auto& codes() const {return code;}
-    const auto& globals() const {return global;}
+    const auto& strs() const { return const_string_table; }
+    const auto& nums() const { return const_number_table; }
+    const auto& natives() const { return native_function; }
+    const auto& codes() const { return code; }
+    const auto& globals() const { return global; }
 
 public:
     codegen() = default;

src/nasal_dbg.cpp

@@ -163,7 +163,13 @@ void dbg::step_info() {
 
     begin = (ctx.pc>>3)==0? 0:((ctx.pc>>3)<<3);
     end = (1+(ctx.pc>>3))<<3;
-    codestream::set(const_number, const_string, native_function.data(), files);
+    codestream::set(
+        const_number,
+        const_string,
+        global_symbol_name,
+        native_function.data(),
+        files
+    );
 
     std::clog << "\nnext bytecode:\n";
     for(u64 i = begin; i<end && bytecode[i].op!=op_exit; ++i) {
@@ -290,7 +296,7 @@ void dbg::run(const codegen& gen,
             counter.dump_all_code_line_counter(std::clog):
             counter.dump_this_file_line_counter(std::clog);
     }
-    ngc.info();
+    ngc.status.dump_info();
     ngc.clear();
     imm.clear();
     return;

src/nasal_gc.cpp

@@ -1,44 +1,38 @@
 #include "nasal_gc.h"
-#include "util/util.h"
 
 namespace nasal {
 
 void gc::do_mark_sweep() {
-    using clk = std::chrono::high_resolution_clock;
-    auto begin = clk::now();
-    if (!in_sweep_stage) {
-        mark();
-        in_sweep_stage = true;
-        current_sweep_index = memory.size() - 1;
-    }
-    auto mark_end = clk::now();
-    sweep();
-    // if (!in_sweep_stage) {
-    //     for (auto i : memory) {
-    //         if (i->mark == nas_val::gc_status::found) {
-    //             i->mark = nas_val::gc_status::uncollected;
-    //         }
-    //     }
-    // }
-    auto sweep_end = clk::now();
+    count_mark_time();
+    count_sweep_time();
+}
 
-    auto total_time = (sweep_end-begin).count();
-    auto mark_time = (mark_end-begin).count();
-    auto sweep_time = (sweep_end-mark_end).count();
-    worktime += total_time;
-    max_time = max_time<total_time? total_time:max_time;
-    max_mark_time = max_mark_time<mark_time? mark_time:max_mark_time;
-    max_sweep_time = max_sweep_time<sweep_time? sweep_time:max_sweep_time;
+void gc::count_mark_time() {
+    if (in_incremental_sweep_stage) {
+        return;
+    }
+
+    status.stamp();
+    mark();
+    status.elapsed_mark_time();
+
+    in_incremental_sweep_stage = true;
+    current_sweep_index = memory.size() - 1;
+}
+
+void gc::count_sweep_time() {
+    status.stamp();
+    sweep();
+    status.elapsed_sweep_time();
 }
 
 void gc::mark() {
     std::vector<var> bfs;
     mark_context_root(bfs);
 
-    // concurrent mark, experimental
-    if (memory.size() > gc::concurrent_threshold() && bfs.size() > 16) {
-        flag_concurrent_mark_triggered = true;
-        usize size = bfs.size();
+    // concurrent mark
+    if (memory.size() > UINT16_MAX * 16 && bfs.size() > 16) {
+        auto size = bfs.size();
         std::thread t0(&gc::concurrent_mark, this, std::ref(bfs), 0, size/4);
         std::thread t1(&gc::concurrent_mark, this, std::ref(bfs), size/4, size/2);
         std::thread t2(&gc::concurrent_mark, this, std::ref(bfs), size/2, size/4*3);
@@ -190,14 +184,17 @@ void gc::mark_map(std::vector<var>& bfs_queue, nas_map& mp) {
 }
 
 void gc::sweep() {
-    const i64 threshold = 65536 / 4;
+    // if threshold is too small, too many allocated objects will be marked as "found"
+    // objects with "found" will be marked to "uncollected" in the next gc cycle
+    // this will cause memory wasting.
+    const i64 threshold = 4096;
     for (i64 it = 0; it < threshold; ++it) {
         if (current_sweep_index - it < 0) {
             break;
         }
         auto i = memory[current_sweep_index - it];
         if (i->mark==nas_val::gc_status::uncollected) {
-            unused[static_cast<u8>(i->type)-static_cast<u8>(vm_type::vm_str)].push_back(i);
+            unused[static_cast<u32>(i->type)-static_cast<u32>(vm_type::vm_str)].push_back(i);
             i->mark = nas_val::gc_status::collected;
         } else if (i->mark==nas_val::gc_status::found) {
             i->mark = nas_val::gc_status::uncollected;
@@ -205,15 +202,14 @@ void gc::sweep() {
     }
     current_sweep_index -= threshold;
     if (current_sweep_index < 0) {
-        in_sweep_stage = false;
+        in_incremental_sweep_stage = false;
         current_sweep_index = 0;
     }
-    return;
 }
 
 void gc::extend(const vm_type type) {
-    const u8 index = static_cast<u8>(type)-static_cast<u8>(vm_type::vm_str);
-    object_size[index] += incr[index];
+    const u32 index = static_cast<u32>(type)-static_cast<u32>(vm_type::vm_str);
+    status.object_size[index] += incr[index];
 
     for(u64 i = 0; i<incr[index]; ++i) {
         // no need to check, will be killed if memory is not enough
@@ -249,11 +245,8 @@ void gc::extend(const vm_type type) {
 
 void gc::init(const std::vector<std::string>& constant_strings,
               const std::vector<std::string>& argv) {
-    // initialize counters
-    worktime = 0;
-    for(u8 i = 0; i<gc_type_size; ++i) {
-        object_size[i] = gc_count[i] = alloc_count[i] = 0;
-    }
+    // initialize gc status recorder
+    status.init();
 
     // coroutine pointer set to nullptr
     cort = nullptr;
@@ -292,7 +285,7 @@ void gc::clear() {
         delete i;
     }
     memory.clear();
-    for(u8 i = 0; i<gc_type_size; ++i) {
+    for(u32 i = 0; i<GC_TYPE_SIZE; ++i) {
         unused[i].clear();
     }
     for(auto& i : strs) {
@@ -302,167 +295,33 @@ void gc::clear() {
     env_argv.clear();
 }
 
-void gc::info() const {
-    util::windows_code_page_manager wm;
-    wm.set_utf8_output();
-
-    using std::left;
-    using std::setw;
-    using std::setfill;
-    using std::setprecision;
-
-    const char* used_table_name[] = {
-        "object type",
-        "gc count",
-        "alloc count",
-        "memory size",
-        "detail",
-        "time spend",
-        "gc time",
-        "avg time",
-        "max gc",
-        "max mark",
-        "max sweep",
-        nullptr
-    };
-    const char* name[] = {
-        "string",
-        "vector",
-        "hashmap",
-        "function",
-        "upvalue",
-        "ghost",
-        "coroutine",
-        "namespace",
-        nullptr
-    };
-
-    usize indent = 0, len = 0;
-    for(usize i = 0; used_table_name[i]; ++i) {
-        len = std::string(used_table_name[i]).length();
-        indent = indent<len? len:indent;
-    }
-    for(usize i = 0; name[i]; ++i) {
-        len = std::string(name[i]).length();
-        indent = indent<len? len:indent;
-    }
-    for(u32 i = 0; i<gc_type_size; ++i) {
-        len = std::to_string(gc_count[i]).length();
-        indent = indent<len? len:indent;
-        len = std::to_string(alloc_count[i]).length();
-        indent = indent<len? len:indent;
-        len = std::to_string(object_size[i]).length();
-        indent = indent<len? len:indent;
-    }
-    auto indent_string = std::string("──");
-    for(usize i = 0; i<indent; ++i) {
-        indent_string += "─";
-    }
-    const auto first_line = "╭" + indent_string + "┬" +
-                            indent_string + "┬" +
-                            indent_string + "┬" +
-                            indent_string + "╮";
-    const auto second_line = "├" + indent_string + "┼" +
-                             indent_string + "┼" +
-                             indent_string + "┼" +
-                             indent_string + "┤";
-    const auto mid_line = "├" + indent_string + "┼" +
-                          indent_string + "┴" +
-                          indent_string + "┴" +
-                          indent_string + "┤";
-    const auto another_mid_line = "├" + indent_string + "┼" +
-                                  indent_string + "─" +
-                                  indent_string + "─" +
-                                  indent_string + "┤";
-    const auto last_line = "╰" + indent_string + "┴" +
-                           indent_string + "─" +
-                           indent_string + "─" +
-                           indent_string + "╯";
-
-    std::clog << "\n" << first_line << "\n";
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "object type";
-    std::clog << " │ " << left << setw(indent) << setfill(' ') << "gc count";
-    std::clog << " │ " << left << setw(indent) << setfill(' ') << "alloc count";
-    std::clog << " │ " << left << setw(indent) << setfill(' ') << "memory size";
-    std::clog << " │\n" << second_line << "\n";
-
-    double total = 0;
-    for(u8 i = 0; i<gc_type_size; ++i) {
-        if (!gc_count[i] && !alloc_count[i] && !object_size[i]) {
-            continue;
-        }
-        total += static_cast<f64>(gc_count[i]);
-        std::clog << "│ " << left << setw(indent) << setfill(' ') << name[i];
-        std::clog << " │ " << left << setw(indent) << setfill(' ') << gc_count[i];
-        std::clog << " │ " << left << setw(indent) << setfill(' ') << alloc_count[i];
-        std::clog << " │ " << left << setw(indent) << setfill(' ') << object_size[i];
-        std::clog << " │\n";
-    }
-    std::clog << mid_line << "\n";
-
-    const auto den = std::chrono::high_resolution_clock::duration::period::den;
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "detail";
-    std::clog << " │ " << left << setw(indent) << setfill(' ') << "time spend";
-    std::clog << "   " << left << setw(indent) << setfill(' ') << " ";
-    std::clog << "   " << left << setw(indent) << setfill(' ') << " ";
-    std::clog << " │\n" << another_mid_line << "\n";
-
-    const auto gc_time = worktime*1.0/den*1000;
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "gc time";
-    std::clog << " │ " << setw(indent-3) << setprecision(4) << gc_time << " ms";
-    std::clog << setw(indent*2+7) << " " << "│\n";
-
-    const auto avg_time = worktime*1.0/den*1000/total;
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "avg time";
-    std::clog << " │ " << setw(indent-3) << setprecision(4) << avg_time << " ms";
-    std::clog << setw(indent*2+7) << " " << "│\n";
-
-    const auto max_gc = max_time*1.0/den*1000;
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "max gc";
-    std::clog << " │ " << setw(indent-3) << setprecision(4) << max_gc << " ms";
-    std::clog << setw(indent*2+7) << " " << "│\n";
-
-    const auto max_mark = max_mark_time*1.0/den*1000;
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "max mark";
-    std::clog << " │ " << setw(indent-3) << setprecision(4) << max_mark << " ms";
-    std::clog << setw(indent*2+7) << " " << "│\n";
-
-    const auto max_sweep = max_sweep_time*1.0/den*1000;
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "max sweep";
-    std::clog << " │ " << setw(indent-3) << setprecision(4) << max_sweep << " ms";
-    std::clog << setw(indent*2+7) << " " << "│\n";
-
-    std::clog << "│ " << left << setw(indent) << setfill(' ') << "concurrent";
-    std::clog << " │ " << setw(indent)
-              << (flag_concurrent_mark_triggered? "true":"false");
-    std::clog << setw(indent*2+7) << " " << "│\n";
-
-    std::clog << last_line << "\n";
-
-    wm.restore_code_page();
-}
-
 var gc::alloc(const vm_type type) {
     const u32 index = static_cast<u32>(type)-static_cast<u32>(vm_type::vm_str);
-    ++alloc_count[index];
+    ++status.alloc_count[index];
     // if still in incremental sweep stage? do it
     // if not in incremental sweep stage, run a new gc cycle
-    if (in_sweep_stage || unused[index].empty()) {
-        ++gc_count[index];
+    if (in_incremental_sweep_stage) {
+        do_mark_sweep();
+    } else if (unused[index].empty()) {
+        ++status.gc_cycle_trigger_count[index];
         do_mark_sweep();
     }
     // if in incremental sweep stage, but the unused list is empty,
     // do it until the unused list has something
-    while (unused[index].empty() && in_sweep_stage) {
+    while (unused[index].empty() && in_incremental_sweep_stage) {
         do_mark_sweep();
     }
     // after all gc stages, still get empty list, extend
     if (unused[index].empty()) {
         extend(type);
     }
+
     var ret = var::gcobj(unused[index].back());
     ret.val.gcobj->clear();
-    ret.val.gcobj->mark = in_sweep_stage
+
+    // if incremental sweep stage, mark it as found
+    // but be aware that it may be collected in next gc cycle
+    ret.val.gcobj->mark = in_incremental_sweep_stage
         ? nas_val::gc_status::found
         : nas_val::gc_status::uncollected;
     unused[index].pop_back();
@@ -485,9 +344,9 @@ void gc::context_change(nas_co* co) {
 
 void gc::context_reserve() {
     // pc = 0 means this coroutine is finished
-    cort->status = running_context->pc?
-        nas_co::status::suspended:
-        nas_co::status::dead;
+    cort->status = running_context->pc
+        ? nas_co::status::suspended
+        : nas_co::status::dead;
 
     // store running state to coroutine
     cort->ctx = *running_context;

src/nasal_gc.h

@@ -17,11 +17,12 @@
 
 #include "nasal.h"
 #include "nasal_type.h"
+#include "util/gc_stat.h"
 
 namespace nasal {
 
 struct free_list {
-    std::vector<nas_val*> elem[gc_type_size];
+    std::vector<nas_val*> elem[GC_TYPE_SIZE];
 
     auto& operator[](i64 index) {
         return elem[index];
@@ -50,7 +51,7 @@ struct gc {
     free_list unused;               // gc free list
 
     /* heap increase size */
-    u64 incr[gc_type_size] = {
+    u64 incr[GC_TYPE_SIZE] = {
         256, // vm_str
         256, // vm_vec
         256, // vm_hash
@@ -65,16 +66,9 @@ struct gc {
     u64 total_object_count = 0;
 
     /* values for analysis */
-    u64 object_size[gc_type_size];
-    u64 gc_count[gc_type_size];
-    u64 alloc_count[gc_type_size];
-    i64 worktime = 0;
-    i64 max_time = 0;
-    i64 max_mark_time = 0;
-    i64 max_sweep_time = 0;
-    bool flag_concurrent_mark_triggered = false;
+    gc_stat status;
 
-    bool in_sweep_stage = false;
+    bool in_incremental_sweep_stage = false;
     i64 current_sweep_index = 0;
 
     void set(context* _ctx, var* _global, usize _size) {
@@ -86,6 +80,8 @@ struct gc {
 private:
     /* gc functions */
     void do_mark_sweep();
+    void count_mark_time();
+    void count_sweep_time();
     void mark();
     void concurrent_mark(std::vector<var>&, usize, usize);
     void mark_context_root(std::vector<var>&);
@@ -99,27 +95,21 @@ private:
     void mark_map(std::vector<var>&, nas_map&);
     void sweep();
 
-    static const auto concurrent_threshold() {
-        return UINT16_MAX * 16;
-    }
-
 public:
     void extend(const vm_type);
     void init(const std::vector<std::string>&, const std::vector<std::string>&);
     void clear();
-    void info() const;
     var alloc(const vm_type);
     void context_change(nas_co*);
     void context_reserve();
 
 public:
-    double get_gc_time_ms() const {
-        const auto den = std::chrono::high_resolution_clock::duration::period::den;
-        return worktime * 1.0 / den * 1000.0;
+    f64 get_gc_time_ms() const {
+        return status.gc_time_ms();
     }
 
     // not very accurate
-    double get_total_memory() const {
+    f64 get_total_memory() const {
         return total_object_count * 3.5 / 1024.0 / 1024.0;
     }
 

src/nasal_opcode.cpp

@@ -5,12 +5,31 @@ namespace nasal {
 
 void codestream::set(const f64* number_list,
                      const std::string* string_list,
+                     const std::unordered_map<std::string, u64>& globals,
                      const nasal_builtin_table* native_table,
                      const std::string* file_list) {
     const_number = number_list;
     const_string = string_list;
     natives = native_table;
     files = file_list;
+
+    global_variable.resize(globals.size());
+    for(auto& [name, index]: globals) {
+        global_variable[index] = name;
+    }
+}
+
+void codestream::set(const f64* number_list,
+                     const std::string* string_list,
+                     const std::vector<std::string>& globals,
+                     const nasal_builtin_table* native_table,
+                     const std::string* file_list) {
+    const_number = number_list;
+    const_string = string_list;
+    natives = native_table;
+    files = file_list;
+
+    global_variable = globals;
 }
 
 void codestream::dump(std::ostream& out) const {
@@ -93,13 +112,16 @@ void codestream::dump(std::ostream& out) const {
         case op_jmp:
         case op_jt:
         case op_jf:
-        case op_callg:
-        case op_mcallg:
         case op_loadg:
         case op_calll:
         case op_mcalll:
         case op_loadl:
             out << hex << "0x" << num << dec; break;
+        case op_mcallg:
+        case op_callg:
+            out << hex << "0x" << num << dec;
+            out << " (" << util::rawstr(global_variable[num], 32) << ")";
+            break;
         case op_callb:
             out << hex << "0x" << num << dec;
             out << " <" << natives[num].name << "@0x";

src/nasal_opcode.h

@@ -4,6 +4,10 @@
 #include "natives/builtin.h"
 
 #include <iostream>
+#include <vector>
+#include <cstring>
+#include <sstream>
+#include <unordered_map>
 
 namespace nasal {
 
@@ -207,16 +211,22 @@ private:
     inline static const std::string* const_string = nullptr;
     inline static const nasal_builtin_table* natives = nullptr;
     inline static const std::string* files = nullptr;
+    inline static std::vector<std::string> global_variable;
     
 public:
     codestream(const opcode& c, const u64 i): code(c), index(i) {}
     static void set(const f64*,
                     const std::string*,
+                    const std::unordered_map<std::string, u64>&,
+                    const nasal_builtin_table*,
+                    const std::string* file_list = nullptr);
+    static void set(const f64*,
+                    const std::string*,
+                    const std::vector<std::string>&,
                     const nasal_builtin_table*,
                     const std::string* file_list = nullptr);
     void dump(std::ostream&) const;
+    friend std::ostream& operator<<(std::ostream&, const codestream&);
 };
 
-std::ostream& operator<<(std::ostream&, const codestream&);
-
 }

src/nasal_type.h

@@ -35,7 +35,7 @@ enum class vm_type: u8 {
 };
 
 // size of gc object type
-const u32 gc_type_size =
+const u32 GC_TYPE_SIZE =
     static_cast<u32>(vm_type::vm_type_size_max) -
     static_cast<u32>(vm_type::vm_str);
 

src/nasal_vm.cpp

@@ -327,7 +327,13 @@ void vm::trace_back() {
 
     std::clog << "\nback trace ";
     std::clog << (ngc.cort? "(coroutine)":"(main)") << "\n";
-    codestream::set(const_number, const_string, native_function.data(), files);
+    codestream::set(
+        const_number,
+        const_string,
+        global_symbol_name,
+        native_function.data(),
+        files
+    );
 
     for(u64 p = 0, same = 0, prev = 0xffffffff; !ret.empty(); prev = p, ret.pop()) {
         if ((p = ret.top())==prev) {
@@ -717,7 +723,7 @@ void vm::run(const codegen& gen,
 // all nasal programs should end here
 vmexit:
     if (verbose) {
-        ngc.info();
+        ngc.status.dump_info();
     }
     imm.clear();
     if (!is_repl_mode) {

src/natives/builtin.cpp

@@ -723,27 +723,17 @@ var builtin_gcextend(context* ctx, gc* ngc) {
 }
 
 var builtin_gcinfo(context* ctx, gc* ngc) {
-    const auto den = std::chrono::high_resolution_clock::duration::period::den;
     var res = ngc->alloc(vm_type::vm_hash);
-
-    f64 total = 0;
-    for(u32 i = 0; i<gc_type_size; ++i) {
-        total += ngc->gc_count[i];
-    }
-
-
     auto& map = res.hash().elems;
-    const auto worktime = static_cast<f64>(ngc->worktime);
-    const auto max_time = static_cast<f64>(ngc->max_time);
-    const auto max_mark_time = static_cast<f64>(ngc->max_mark_time);
-    const auto max_sweep_time = static_cast<f64>(ngc->max_sweep_time);
-
     // using ms
-    map["total"] = var::num(worktime/den*1000);
-    map["average"] = var::num(worktime/den*1000/total);
-    map["max_gc"] = var::num(max_time/den*1000);
-    map["max_mark"] = var::num(max_mark_time/den*1000);
-    map["max_sweep"] = var::num(max_sweep_time/den*1000);
+    map["total"] = var::num(ngc->status.gc_time_ms());
+    map["average"] = var::num(ngc->status.avg_time_ms());
+    map["mark_count"] = var::num(ngc->status.total_mark_count);
+    map["sweep_count"] = var::num(ngc->status.total_sweep_count);
+    map["avg_mark"] = var::num(ngc->status.avg_mark_time_ms());
+    map["avg_sweep"] = var::num(ngc->status.avg_sweep_time_ms());
+    map["max_mark"] = var::num(ngc->status.max_mark_time_ms());
+    map["max_sweep"] = var::num(ngc->status.max_sweep_time_ms());
     return res;
 }
 

src/util/gc_stat.cpp

@@ -0,0 +1,193 @@
+#include "util/util.h"
+#include "util/gc_stat.h"
+
+#include <chrono>
+#include <iomanip>
+
+namespace nasal {
+
+void gc_stat::init() {
+    for (i64 i = 0; i < GC_TYPE_SIZE; i++) {
+        object_size[i] = 0;
+        alloc_count[i] = 0;
+        gc_cycle_trigger_count[i] = 0;
+    }
+
+    total_mark_count = 0;
+    total_sweep_count = 0;
+
+    total_mark_time = 0;
+    total_sweep_time = 0;
+
+    max_mark_time = 0;
+    max_sweep_time = 0;
+}
+
+f64 gc_stat::gc_time_ms() const {
+    const auto den = std::chrono::high_resolution_clock::duration::period::den;
+    return ((total_mark_time + total_sweep_time) * 1000.0) / den;
+}
+
+f64 gc_stat::avg_time_ms() const {
+    u64 total_gc_cycle = 0;
+    for (i64 i = 0; i < GC_TYPE_SIZE; i++) {
+        total_gc_cycle += gc_cycle_trigger_count[i];
+    }
+    return gc_time_ms() / total_mark_count;
+}
+
+f64 gc_stat::avg_mark_time_ms() const {
+    const auto den = std::chrono::high_resolution_clock::duration::period::den;
+    return (total_mark_time * 1000.0) / den / total_mark_count;
+}
+
+f64 gc_stat::avg_sweep_time_ms() const {
+    const auto den = std::chrono::high_resolution_clock::duration::period::den;
+    return (total_sweep_time * 1000.0) / den / total_sweep_count;
+}
+
+f64 gc_stat::max_mark_time_ms() const {
+    const auto den = std::chrono::high_resolution_clock::duration::period::den;
+    return (max_mark_time * 1000.0) / den;
+}
+
+f64 gc_stat::max_sweep_time_ms() const {
+    const auto den = std::chrono::high_resolution_clock::duration::period::den;
+    return (max_sweep_time * 1000.0) / den;
+}
+
+void gc_stat::dump_info() const {
+    util::windows_code_page_manager wm;
+    wm.set_utf8_output();
+
+    using std::left;
+    using std::setw;
+    using std::setfill;
+    using std::setprecision;
+
+    const char* used_table_name[] = {
+        "object type",
+        "gc cycle",
+        "alloc count",
+        "object count",
+        "detail",
+        "time spend",
+        "gc time",
+        "avg time",
+        "max gc",
+        "max mark",
+        "max sweep"
+    };
+    const char* name[] = {
+        "string",
+        "vector",
+        "hashmap",
+        "function",
+        "upvalue",
+        "ghost",
+        "coroutine",
+        "namespace"
+    };
+
+    // calculate max indent length
+    usize indent = 0;
+    for (auto tname : used_table_name) {
+        auto len = strlen(tname);
+        indent = indent<len? len:indent;
+    }
+    for (auto n : name) {
+        auto len = strlen(n);
+        indent = indent<len? len:indent;
+    }
+    for(u32 i = 0; i < GC_TYPE_SIZE; ++i) {
+        auto len = std::to_string(gc_cycle_trigger_count[i]).length();
+        indent = indent<len? len:indent;
+        len = std::to_string(alloc_count[i]).length();
+        indent = indent<len? len:indent;
+        len = std::to_string(object_size[i]).length();
+        indent = indent<len? len:indent;
+    }
+
+    auto indent_string = std::string("──");
+    for(usize i = 0; i < indent; ++i) {
+        indent_string += "─";
+    }
+
+    const auto first_line = "╭" + indent_string + "┬" +
+                            indent_string + "┬" +
+                            indent_string + "┬" +
+                            indent_string + "╮";
+    const auto second_line = "├" + indent_string + "┼" +
+                             indent_string + "┼" +
+                             indent_string + "┼" +
+                             indent_string + "┤";
+    const auto mid_line = "├" + indent_string + "┼" +
+                          indent_string + "┴" +
+                          indent_string + "┴" +
+                          indent_string + "┤";
+    const auto another_mid_line = "├" + indent_string + "┼" +
+                                  indent_string + "─" +
+                                  indent_string + "─" +
+                                  indent_string + "┤";
+    const auto last_line = "╰" + indent_string + "┴" +
+                           indent_string + "─" +
+                           indent_string + "─" +
+                           indent_string + "╯";
+
+    std::clog << "\n" << first_line << "\n";
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "object type";
+    std::clog << " │ " << left << setw(indent) << setfill(' ') << "gc cycle";
+    std::clog << " │ " << left << setw(indent) << setfill(' ') << "alloc count";
+    std::clog << " │ " << left << setw(indent) << setfill(' ') << "object count";
+    std::clog << " │\n" << second_line << "\n" << std::internal;
+
+    for (u32 i = 0; i < GC_TYPE_SIZE; ++i) {
+        if (!gc_cycle_trigger_count[i] &&
+            !alloc_count[i] &&
+            !object_size[i]) {
+            continue;
+        }
+        std::clog << "│ " << left << setw(indent) << setfill(' ') << name[i];
+        std::clog << " │ " << left << setw(indent) << setfill(' ') << gc_cycle_trigger_count[i];
+        std::clog << " │ " << left << setw(indent) << setfill(' ') << alloc_count[i];
+        std::clog << " │ " << left << setw(indent) << setfill(' ') << object_size[i];
+        std::clog << " │\n" << std::internal;
+    }
+    std::clog << mid_line << "\n";
+
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "detail";
+    std::clog << " │ " << left << setw(indent) << setfill(' ') << "time spend";
+    std::clog << "   " << left << setw(indent) << setfill(' ') << " ";
+    std::clog << "   " << left << setw(indent) << setfill(' ') << " ";
+    std::clog << " │\n" << another_mid_line << "\n";
+
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "gc time";
+    std::clog << " │ " << setw(indent-3) << setprecision(4) << gc_time_ms() << " ms";
+    std::clog << setw(indent*2+7) << " " << "│\n";
+
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "avg time";
+    std::clog << " │ " << setw(indent-3) << setprecision(4) << avg_time_ms() << " ms";
+    std::clog << setw(indent*2+7) << " " << "│\n";
+
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "avg mark";
+    std::clog << " │ " << setw(indent-3) << setprecision(4) << avg_mark_time_ms() << " ms";
+    std::clog << setw(indent*2+7) << " " << "│\n";
+
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "avg sweep";
+    std::clog << " │ " << setw(indent-3) << setprecision(4) << avg_sweep_time_ms() << " ms";
+    std::clog << setw(indent*2+7) << " " << "│\n";
+
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "max mark";
+    std::clog << " │ " << setw(indent-3) << setprecision(4) << max_mark_time_ms() << " ms";
+    std::clog << setw(indent*2+7) << " " << "│\n";
+
+    std::clog << "│ " << left << setw(indent) << setfill(' ') << "max sweep";
+    std::clog << " │ " << setw(indent-3) << setprecision(4) << max_sweep_time_ms() << " ms";
+    std::clog << setw(indent*2+7) << " " << "│\n";
+
+    std::clog << last_line << "\n" << std::internal;
+
+    wm.restore_code_page();
+}
+
+}

src/util/gc_stat.h

@@ -0,0 +1,57 @@
+#pragma once
+
+#include "nasal.h"
+#include "nasal_type.h"
+
+#include <chrono>
+
+namespace nasal {
+
+struct gc_stat {
+    u64 object_size[GC_TYPE_SIZE];
+    u64 gc_cycle_trigger_count[GC_TYPE_SIZE];
+    u64 alloc_count[GC_TYPE_SIZE];
+
+    u64 total_mark_count = 0;
+    u64 total_sweep_count = 0;
+
+    i64 total_mark_time = 0;
+    i64 total_sweep_time = 0;
+
+    i64 max_mark_time = 0;
+    i64 max_sweep_time = 0;
+
+    std::chrono::time_point<std::chrono::high_resolution_clock> start_time;
+
+    void stamp() {
+        start_time = std::chrono::high_resolution_clock::now();
+    }
+
+    void elapsed_mark_time() {
+        auto end = std::chrono::high_resolution_clock::now();
+        auto mark_time = (end - start_time).count();
+        ++total_mark_count;
+        total_mark_time += mark_time;
+        max_mark_time = max_mark_time > mark_time ? max_mark_time : mark_time;
+    }
+
+    void elapsed_sweep_time() {
+        auto end = std::chrono::high_resolution_clock::now();
+        auto sweep_time = (end - start_time).count();
+        ++total_sweep_count;
+        total_sweep_time += sweep_time;
+        max_sweep_time = max_sweep_time > sweep_time ? max_sweep_time : sweep_time;
+    }
+
+    void init();
+    f64 gc_time_ms() const;
+    f64 avg_time_ms() const;
+    f64 avg_mark_time_ms() const;
+    f64 avg_sweep_time_ms() const;
+    f64 max_mark_time_ms() const;
+    f64 max_sweep_time_ms() const;
+
+    void dump_info() const;
+};
+
+}

test/gc_test.nas

@@ -23,15 +23,18 @@ var test_func = func(test_processes...) {
     );
 
     var info = runtime.gc.info();
-    println("+##-gc-----------------");
-    println("| average  : ", info.average, " ms");
-    println("| max gc   : ", info.max_gc, " ms");
-    println("| max mark : ", info.max_mark, " ms");
-    println("| max sweep: ", info.max_sweep, " ms");
-    println("+----------------------");
+    println("+##-gc----------------------");
+    println("| avg gc cycle : ", int(1000 / info.average), " exec/sec");
+    println("| avg mark     : ", int(1000 / info.avg_mark), " exec/sec");
+    println("| avg sweep    : ", int(1000 / info.avg_sweep), " exec/sec");
+    println("| mark count   : ", info.mark_count);
+    println("| sweep count  : ", info.sweep_count);
+    println("| max mark     : ", info.max_mark, " ms");
+    println("| max sweep    : ", info.max_sweep, " ms");
+    println("+---------------------------");
 }
 
-var MAX_ITER_NUM = 1e5;
+var MAX_ITER_NUM = 0.5e5;
 
 var append_vec = func {
     var res = [];