From 04097341ac433ef27b4e1cc2aa0a090daaf92e6c Mon Sep 17 00:00:00 2001 From: ValKmjolnir Date: Wed, 1 Jan 2025 18:28:58 +0800 Subject: [PATCH] :art: dump gc time occupation --- makefile | 10 +++++----- src/main.cpp | 9 ++++++++- src/nasal_gc.h | 6 ++++++ src/nasal_vm.cpp | 23 +++++++++++++++++------ src/nasal_vm.h | 4 ++++ std/argparse.nas | 2 +- std/lib.nas | 2 +- test/feigenbaum.nas | 19 +++++++++++-------- test/mandelbrot.nas | 31 ++++++++++++++++--------------- test/mandelbrotset.nas | 4 ++-- 10 files changed, 71 insertions(+), 39 deletions(-) diff --git a/makefile b/makefile index 4482512..fb2f959 100644 --- a/makefile +++ b/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 -e test/trait.nas + @ ./nasal -t test/subprocess_test.nas + @ ./nasal -t test/trait.nas @ ./nasal -t -d test/turingmachine.nas - @ ./nasal -d test/wavecollapse.nas - @ ./nasal -d test/wavecity.nas - @ ./nasal test/word_collector.nas test/md5compare.nas + @ ./nasal -t -d test/wavecollapse.nas + @ ./nasal -t -d test/wavecity.nas + @ ./nasal -t test/word_collector.nas test/md5compare.nas @ ./nasal -t -d test/ycombinator.nas diff --git a/src/main.cpp b/src/main.cpp index aac6c26..3e0a4ea 100644 --- a/src/main.cpp +++ b/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(); 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((end - start).count())/den; + double gc_time_sec = gc_time_ms / 1000.0; std::clog << "process exited after "; - std::clog << static_cast((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"; } } diff --git a/src/nasal_gc.h b/src/nasal_gc.h index 5312d60..4827608 100644 --- a/src/nasal_gc.h +++ b/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); diff --git a/src/nasal_vm.cpp b/src/nasal_vm.cpp index 3a57ec4..c04c7ae 100644 --- a/src/nasal_vm.cpp +++ b/src/nasal_vm.cpp @@ -226,7 +226,7 @@ void vm::function_call_trace() { std::stack callsite; // load call trace - for(var* i = bottom; i<=top; ++i) { + for(var* i = bottom; i <= top; ++i) { // i-1 is the callsite program counter of this function if (i->is_addr() && i+2<=top && (i+1)->is_ret() && (i+1)->ret()>0 && @@ -238,7 +238,7 @@ void vm::function_call_trace() { // another condition may exist // have ret pc on stack, but no function at the top of the ret pc - for(var * i = top; i>=bottom; --i) { + for(var * i = top; i >= bottom; --i) { if ((i->is_addr() && i+2<=top && (i+1)->is_ret() && !(i+2)->is_func()) || (i->is_addr() && i+1<=top && i+2>top && (i+1)->is_ret())) { functions.push(&ctx.funcr.func()); @@ -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(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(); - stack_info(); + + // trace back contains bytecode info, dump in verbose mode + if (verbose) { + trace_back(); + } + + // 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); } diff --git a/src/nasal_vm.h b/src/nasal_vm.h index 258c972..62c1f87 100644 --- a/src/nasal_vm.h +++ b/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) { diff --git a/std/argparse.nas b/std/argparse.nas index a183329..507b7a2 100644 --- a/std/argparse.nas +++ b/std/argparse.nas @@ -151,7 +151,7 @@ var _parse = func(parser, args, result_hash) { return; } -var _add_command = func(parser, long, short, help, need_arg , need_nargs) { +var _add_command = func(parser, long, short, help, need_arg, need_nargs) { var new_command = { full_name: long, short_name: short, diff --git a/std/lib.nas b/std/lib.nas index e4b556a..da1eec6 100644 --- a/std/lib.nas +++ b/std/lib.nas @@ -380,7 +380,7 @@ var bind = func(function, locals, outer_scope = nil) { die("this runtime does not support bind"); } -var call = func(function ,args = nil, _me = nil, locals = nil, error = nil) { +var call = func(function, args = nil, _me = nil, locals = nil, error = nil) { die("this runtime does not support call"); } diff --git a/test/feigenbaum.nas b/test/feigenbaum.nas index d56d315..811f135 100644 --- a/test/feigenbaum.nas +++ b/test/feigenbaum.nas @@ -16,25 +16,29 @@ var ppm = func(filename, width, height, RGB) { io.close(fd); } -var width = 1920; -var height = 1080; +var width = 1920 * 2; +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) { - res = 255; + if (abs(tmp-x)<0.0005) { + 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 c~c~c; + return char(R) ~ char(G) ~ char(B); } ppm("feigenbaum.ppm", width, height, RGB); diff --git a/test/mandelbrot.nas b/test/mandelbrot.nas index 59722e3..1e712d9 100644 --- a/test/mandelbrot.nas +++ b/test/mandelbrot.nas @@ -1,22 +1,23 @@ -var (yMin,yMax,xMin,xMax,line)=(-0.2,0.2,-1.5,-1.0,""); -var (yDel,xDel)=(yMax-yMin,xMax-xMin); -for(var yPixel=0;yPixel<24;yPixel+=1) { - var y=(yPixel/24)*yDel+yMin; - for(var xPixel=0;xPixel<80;xPixel+=1) { - var x=(xPixel/80)*xDel+xMin; - var pixel=" "; - var (x0,y0)=(x,y); - for(var iter=0;iter<80;iter+=1) { - var x1=(x0*x0)-(y0*y0)+x; - var y1=2*x0*y0+y; - (x0,y0)=(x1,y1); +var (yMin, yMax, xMin, xMax, line) = (-0.2, 0.2, -1.5, -1.0, ""); +var (yDel, xDel) = (yMax-yMin, xMax-xMin); +for(var yPixel = 0; yPixel < 24; yPixel += 1) { + var y = (yPixel/24)*yDel+yMin; + for(var xPixel = 0; xPixel < 80; xPixel += 1) { + var x = (xPixel/80)*xDel+xMin; + var pixel = " "; + var (x0, y0) = (x, y); + 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); if ((x0*x0)+(y0*y0)>4) { - pixel=chr(" .:;+=xX$&"[iter/8]); + pixel = chr(" .:;+=xX$&"[iter/8]); break; } } - line~=pixel; + line ~= pixel; } - line~='\n'; + line ~= '\n'; } + print(line); \ No newline at end of file diff --git a/test/mandelbrotset.nas b/test/mandelbrotset.nas index c4573bc..064d3c8 100644 --- a/test/mandelbrotset.nas +++ b/test/mandelbrotset.nas @@ -15,8 +15,8 @@ var ppm = func(filename, width, height, RGB) { io.close(fd); } -var width = 1920; -var height = 1080; +var width = 1920 * 2; +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);