🎨 dump gc time occupation

makefile

@@ -333,10 +333,10 @@ test:
 	@ ./nasal -t -d test/regex_test.nas
 	@ ./nasal -t -d test/replace_test.nas
 	@ ./nasal -e test/scalar.nas hello world
-	@ ./nasal test/subprocess_test.nas
+	@ ./nasal -t test/subprocess_test.nas
-	@ ./nasal -e test/trait.nas
+	@ ./nasal -t test/trait.nas
 	@ ./nasal -t -d test/turingmachine.nas
-	@ ./nasal -d test/wavecollapse.nas
+	@ ./nasal -t -d test/wavecollapse.nas
-	@ ./nasal -d test/wavecity.nas
+	@ ./nasal -t -d test/wavecity.nas
-	@ ./nasal test/word_collector.nas test/md5compare.nas
+	@ ./nasal -t test/word_collector.nas test/md5compare.nas
 	@ ./nasal -t -d test/ycombinator.nas

src/main.cpp

@@ -121,6 +121,7 @@ void execute(const nasal::cli::cli_config& config) {
 
     // run
     const auto start = clk::now();
+    double gc_time_ms = 0.0;
     if (config.has(option::cli_debug_mode)) {
         auto debugger = std::make_unique<nasal::dbg>();
         debugger->run(
@@ -130,6 +131,7 @@ void execute(const nasal::cli::cli_config& config) {
             config.has(option::cli_profile),
             config.has(option::cli_profile_all)
         );
+        gc_time_ms = debugger->get_gc_time_ms();
     } else if (config.has(option::cli_show_execute_time) ||
                config.has(option::cli_detail_info) ||
                config.has(option::cli_limit_mode) ||
@@ -138,13 +140,18 @@ void execute(const nasal::cli::cli_config& config) {
         runtime->set_detail_report_info(config.has(option::cli_detail_info));
         runtime->set_limit_mode_flag(config.has(option::cli_limit_mode));
         runtime->run(gen, ld, config.nasal_vm_args);
+        gc_time_ms = runtime->get_gc_time_ms();
     }
 
     // get running time
     const auto end = clk::now();
     if (config.has(option::cli_show_execute_time)) {
+        double execute_time_sec = static_cast<f64>((end - start).count())/den;
+        double gc_time_sec = gc_time_ms / 1000.0;
         std::clog << "process exited after ";
-        std::clog << static_cast<f64>((end-start).count())/den << "s.\n\n";
+        std::clog << execute_time_sec << "s, gc time: ";
+        std::clog << gc_time_sec << "s (";
+        std::clog << gc_time_sec / execute_time_sec * 100.0 << "%)\n\n";
     }
 }
 

src/nasal_gc.h

@@ -94,6 +94,12 @@ public:
     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;
+    }
+
 public:
     var newstr(char c) {
         var s = alloc(vm_type::vm_str);

src/nasal_vm.cpp

@@ -254,7 +254,7 @@ void vm::function_call_trace() {
 
     std::clog << "\ncall trace ";
     std::clog << (ngc.cort? "(coroutine)":"(main)") << "\n";
-    std::clog << "  crash occurred in\n       ";
+    std::clog << "  crash occurred at\n       ";
     function_detail_info(ctx.funcr.func());
     std::clog << " at " << files[bytecode[ctx.pc].fidx] << ":";
     std::clog << bytecode[ctx.pc].line << "\n";
@@ -325,7 +325,7 @@ void vm::trace_back() {
     // the first called place has no same calls
 }
 
-void vm::stack_info(const u64 limit = 16) {
+void vm::stack_info(const u64 limit) {
     var* top = ctx.top;
     var* bottom = ctx.stack;
     const auto stack_address = reinterpret_cast<u64>(bottom);
@@ -525,8 +525,16 @@ std::string vm::type_name_string(const var& value) const {
 void vm::die(const std::string& str) {
     std::cerr << "[vm] error: " << str << "\n";
     function_call_trace();
+
+    // trace back contains bytecode info, dump in verbose mode
+    if (verbose) {
         trace_back();
-    stack_info();
+    }
+
+    // verbose will dump more values on stack
+    if (verbose) {
+        stack_info(64);
+    }
 
     // show verbose crash info
     if (verbose) {
@@ -534,6 +542,9 @@ void vm::die(const std::string& str) {
     }
 
     if (!ngc.cort) {
+        if (!verbose) {
+            std::cerr << "\n[vm] use <-d> for detailed crash info.\n\n";
+        }
         // in main context, exit directly
         std::exit(1);
     }

src/nasal_vm.h

@@ -318,6 +318,10 @@ public:
     void set_limit_mode_flag(bool flag) {
         flag_limited_mode = flag;
     }
+
+    auto get_gc_time_ms() const {
+        return ngc.get_gc_time_ms();
+    }
 };
 
 inline bool vm::boolify(const var& val) {

test/feigenbaum.nas

@@ -16,25 +16,29 @@ var ppm = func(filename, width, height, RGB) {
     io.close(fd);
 }
 
-var width = 1920;
+var width = 1920 * 2;
-var height = 1080;
+var height = 1080 * 2;
 var bar = (os.platform()=="windows")?
     process_bar.bar(front:"sharp", back:"point", sep:"line", length:50):
     process_bar.high_resolution_bar(50);
+var abs = math.abs; # alias
 
 var RGB = func(h, w) {
     var r = 2+w*2/width;
     var x = (height-h)/height;
 
-    var res = 0;
+    var (R, G, B) = (0, 0, 0);
+
     var tmp = 0.5;
     for(var i = 0; i<50; i+=1) {
         tmp = r*tmp*(1-tmp);
     }
-    for(var i = 0; i<100; i+=1) {
+    for(var i = 0; i<150; i+=1) {
         tmp = r*tmp*(1-tmp);
-        if (math.abs(tmp-x)<0.001) {
+        if (abs(tmp-x)<0.0005) {
-            res = 255;
+            R = int(255*(150 - i)/150);
+            G = int(255*(150 - i)/150);
+            B = 255;
             break;
         }
     }
@@ -44,8 +48,7 @@ var RGB = func(h, w) {
         print(bar.bar(progress), " ", progress*100, "%          \r");
     }
 
-    var c = char(res);
+    return char(R) ~ char(G) ~ char(B);
-    return c~c~c;
 }
 
 ppm("feigenbaum.ppm", width, height, RGB);

test/mandelbrot.nas

@@ -6,7 +6,7 @@ for(var yPixel=0;yPixel<24;yPixel+=1) {
         var x = (xPixel/80)*xDel+xMin;
         var pixel = " ";
         var (x0, y0) = (x, y);
-        for(var iter=0;iter<80;iter+=1) {
+        for(var iter = 0; iter < 100; iter += 1) {
             var x1 = (x0*x0)-(y0*y0)+x;
             var y1 = 2*x0*y0+y;
             (x0, y0) = (x1, y1);
@@ -19,4 +19,5 @@ for(var yPixel=0;yPixel<24;yPixel+=1) {
     }
     line ~= '\n';
 }
+
 print(line);

test/mandelbrotset.nas

@@ -15,8 +15,8 @@ var ppm = func(filename, width, height, RGB) {
     io.close(fd);
 }
 
-var width = 1920;
+var width = 1920 * 2;
-var height = 1080;
+var height = 1080 * 2;
 var bar = (os.platform()=="windows")?
     process_bar.bar(front:"sharp", back:"point", sep:"line", length:50):
     process_bar.high_resolution_bar(50);