🐛 fix issue #80

Signed-off-by: ValKmjolnir <lhk101lhk101@qq.com>

README.md

@@ -265,7 +265,7 @@ func() {
 ```
 
 ```javascript
-[vm] error: must call a vector/hash/string but get number
+[vm] error: must get element from vector/hash/string, but get number
 
 trace back (main)
   0x000854     47 00 00 00     callv   0x0(a.nas:3)

README_zh.md

@@ -251,7 +251,7 @@ func() {
 ```
 
 ```javascript
-[vm] error: must call a vector/hash/string but get number
+[vm] error: must get element from vector/hash/string, but get number
 
 trace back (main)
   0x000854     47 00 00 00     callv   0x0(a.nas:3)

module/fib.cpp

@@ -61,11 +61,11 @@ void ghost_for_test_destructor(void* ptr) {
     std::cout << "}\n";
 }
 
-void ghost_for_test_gc_marker(void* ptr, std::vector<var>* bfs_queue) {
+void ghost_for_test_gc_marker(void* ptr, std::queue<var>* bfs_queue) {
     std::cout << "ghost_for_test::mark (0x";
     std::cout << std::hex << reinterpret_cast<u64>(ptr) << std::dec << ") {\n";
 
-    bfs_queue->push_back(static_cast<ghost_obj*>(ptr)->test_string);
+    bfs_queue->push(static_cast<ghost_obj*>(ptr)->test_string);
 
     std::cout << "    mark 0x" << std::hex;
     std::cout << reinterpret_cast<u64>(ptr) << std::dec << "->test_string;\n";

src/nasal_gc.cpp

@@ -27,73 +27,40 @@ void gc::count_sweep_time() {
 }
 
 void gc::mark() {
-    std::vector<var> bfs;
+    std::queue<var> bfs;
     mark_context_root(bfs);
 
-    // 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);
-        std::thread t3(&gc::concurrent_mark, this, std::ref(bfs), size/4*3, size);
-        t0.join();
-        t1.join();
-        t2.join();
-        t3.join();
-        return;
-    }
-
-    // normal mark
     while (!bfs.empty()) {
-        var value = bfs.back();
-        bfs.pop_back();
-        if (value.type<=vm_type::vm_num ||
-            value.val.gcobj->mark!=nas_val::gc_status::uncollected) {
+        var value = bfs.front();
+        bfs.pop();
+        if (value.type <= vm_type::vm_num) {
+            continue;
+        }
+        if (value.val.gcobj->mark != nas_val::gc_status::uncollected &&
+            value.val.gcobj->mark != nas_val::gc_status::alloc_in_sweep_stage) {
             continue;
         }
         mark_var(bfs, value);
     }
 }
 
-void gc::concurrent_mark(std::vector<var>& vec, usize begin, usize end) {
-    std::vector<var> bfs;
-    for (auto i = begin; i<end; ++i) {
-        var value = vec[i];
-        if (value.type<=vm_type::vm_num ||
-            value.val.gcobj->mark!=nas_val::gc_status::uncollected) {
-            continue;
-        }
-        mark_var(bfs, value);
-    }
-    while (!bfs.empty()) {
-        var value = bfs.back();
-        bfs.pop_back();
-        if (value.type<=vm_type::vm_num ||
-            value.val.gcobj->mark!=nas_val::gc_status::uncollected) {
-            continue;
-        }
-        mark_var(bfs, value);
-    }
-}
-
-void gc::mark_context_root(std::vector<var>& bfs_queue) {
+void gc::mark_context_root(std::queue<var>& bfs_queue) {
     // scan global
     for (usize i = 0; i < main_context_global_size; ++i) {
         auto& val = main_context_global[i];
         if (val.type > vm_type::vm_num) {
-            bfs_queue.push_back(val);
+            bfs_queue.push(val);
         }
     }
     // scan now running context, this context maybe related to coroutine or main
     for (var* i = running_context->stack; i <= running_context->top; ++i) {
         if (i->type > vm_type::vm_num) {
-            bfs_queue.push_back(*i);
+            bfs_queue.push(*i);
         }
     }
-    bfs_queue.push_back(running_context->funcr);
-    bfs_queue.push_back(running_context->upvalr);
-    bfs_queue.push_back(temp);
+    bfs_queue.push(running_context->funcr);
+    bfs_queue.push(running_context->upvalr);
+    bfs_queue.push(temp);
 
     if (!cort) {
         return;
@@ -102,14 +69,14 @@ void gc::mark_context_root(std::vector<var>& bfs_queue) {
     // coroutine is running, so scan main process stack from mctx
     for (var* i = main_context.stack; i <= main_context.top; ++i) {
         if (i->type > vm_type::vm_num) {
-            bfs_queue.push_back(*i);
+            bfs_queue.push(*i);
         }
     }
-    bfs_queue.push_back(main_context.funcr);
-    bfs_queue.push_back(main_context.upvalr);
+    bfs_queue.push(main_context.funcr);
+    bfs_queue.push(main_context.upvalr);
 }
 
-void gc::mark_var(std::vector<var>& bfs_queue, var& value) {
+void gc::mark_var(std::queue<var>& bfs_queue, var& value) {
     value.val.gcobj->mark = nas_val::gc_status::found;
     switch(value.type) {
         case vm_type::vm_vec: mark_vec(bfs_queue, value.vec()); break;
@@ -123,62 +90,71 @@ void gc::mark_var(std::vector<var>& bfs_queue, var& value) {
     }
 }
 
-void gc::mark_vec(std::vector<var>& bfs_queue, nas_vec& vec) {
+void gc::mark_vec(std::queue<var>& bfs_queue, nas_vec& vec) {
     for (auto& i : vec.elems) {
         if (i.type > vm_type::vm_num) {
-            bfs_queue.push_back(i);
+            bfs_queue.push(i);
         }
     }
 }
 
-void gc::mark_hash(std::vector<var>& bfs_queue, nas_hash& hash) {
+void gc::mark_hash(std::queue<var>& bfs_queue, nas_hash& hash) {
     for (auto& i : hash.elems) {
         if (i.second.type > vm_type::vm_num) {
-            bfs_queue.push_back(i.second);
+            bfs_queue.push(i.second);
         }
     }
 }
 
-void gc::mark_func(std::vector<var>& bfs_queue, nas_func& function) {
+void gc::mark_func(std::queue<var>& bfs_queue, nas_func& function) {
     for (auto& i : function.local) {
         if (i.type > vm_type::vm_num) {
-            bfs_queue.push_back(i);
+            bfs_queue.push(i);
         }
     }
     for (auto& i : function.upval) {
-        bfs_queue.push_back(i);
+        bfs_queue.push(i);
     }
 }
 
-void gc::mark_upval(std::vector<var>& bfs_queue, nas_upval& upval) {
+void gc::mark_upval(std::queue<var>& bfs_queue, nas_upval& upval) {
+    if (upval.on_stack) {
+        for (u64 i = 0; i < upval.size; ++i) {
+            if (upval.stack_frame_offset[i].type > vm_type::vm_num) {
+                bfs_queue.push(upval.stack_frame_offset[i]);
+            }
+        }
+        return;
+    }
+
     for (auto& i : upval.elems) {
         if (i.type > vm_type::vm_num) {
-            bfs_queue.push_back(i);
+            bfs_queue.push(i);
         }
     }
 }
 
-void gc::mark_ghost(std::vector<var>& bfs_queue, nas_ghost& ghost) {
+void gc::mark_ghost(std::queue<var>& bfs_queue, nas_ghost& ghost) {
     if (!ghost.gc_mark_function) {
         return;
     }
     ghost.gc_mark_function(ghost.pointer, &bfs_queue);
 }
 
-void gc::mark_co(std::vector<var>& bfs_queue, nas_co& co) {
-    bfs_queue.push_back(co.ctx.funcr);
-    bfs_queue.push_back(co.ctx.upvalr);
-    for (var* i = co.ctx.stack; i<=co.ctx.top; ++i) {
+void gc::mark_co(std::queue<var>& bfs_queue, nas_co& co) {
+    bfs_queue.push(co.ctx.funcr);
+    bfs_queue.push(co.ctx.upvalr);
+    for (var* i = co.ctx.stack; i <= co.ctx.top; ++i) {
         if (i->type > vm_type::vm_num) {
-            bfs_queue.push_back(*i);
+            bfs_queue.push(*i);
         }
     }
 }
 
-void gc::mark_map(std::vector<var>& bfs_queue, nas_map& mp) {
+void gc::mark_map(std::queue<var>& bfs_queue, nas_map& mp) {
     for (const auto& i : mp.mapper) {
         if (i.second->type > vm_type::vm_num) {
-            bfs_queue.push_back(*i.second);
+            bfs_queue.push(*i.second);
         }
     }
 }
@@ -187,19 +163,22 @@ void gc::sweep() {
     // 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;
+    const i64 threshold = status.calc_sweep_threshold();
     for (i64 it = 0; it < threshold; ++it) {
-        if (current_sweep_index - it < 0) {
+        const auto index = current_sweep_index - it;
+        if (index < 0) {
             break;
         }
-        auto i = memory[current_sweep_index - it];
-        if (i->mark==nas_val::gc_status::uncollected) {
-            unused[static_cast<u32>(i->type)-static_cast<u32>(vm_type::vm_str)].push_back(i);
+        auto i = memory[index];
+        if (i->mark == nas_val::gc_status::uncollected) {
+            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) {
+        } else if (i->mark == nas_val::gc_status::found ||
+                   i->mark == nas_val::gc_status::alloc_in_sweep_stage) {
             i->mark = nas_val::gc_status::uncollected;
         }
     }
+
     current_sweep_index -= threshold;
     if (current_sweep_index < 0) {
         in_incremental_sweep_stage = false;
@@ -208,10 +187,10 @@ void gc::sweep() {
 }
 
 void gc::extend(const vm_type type) {
-    const u32 index = static_cast<u32>(type)-static_cast<u32>(vm_type::vm_str);
+    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) {
+    for (u64 i = 0; i < incr[index]; ++i) {
         // no need to check, will be killed if memory is not enough
         nas_val* tmp = new nas_val(type);
 
@@ -239,8 +218,10 @@ void gc::extend(const vm_type type) {
         default: break;
     }
 
-    // if incr[index] = 1, this will always be 1
     incr[index] = incr[index] + incr[index];
+    if (incr[index] > max_incr[index]) {
+        incr[index] = max_incr[index];
+    }
 }
 
 void gc::init(const std::vector<std::string>& constant_strings,
@@ -296,8 +277,9 @@ void gc::clear() {
 }
 
 var gc::alloc(const vm_type type) {
-    const u32 index = static_cast<u32>(type)-static_cast<u32>(vm_type::vm_str);
+    const u32 index = static_cast<u32>(type) - static_cast<u32>(vm_type::vm_str);
     ++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_incremental_sweep_stage) {
@@ -319,10 +301,14 @@ var gc::alloc(const vm_type type) {
     var ret = var::gcobj(unused[index].back());
     ret.val.gcobj->clear();
 
-    // if incremental sweep stage, mark it as found
-    // but be aware that it may be collected in next gc cycle
+    // if incremental sweep stage, mark it with special state.
+    // to avoid miss-marking objects inside them, because mark stage
+    // will skip scanning objects with "found" mark
+    // if we mark it with "found" mark, objects inside it will not be marked
+    // so they may be treated as unreferenced, which is not expected.
+    // be aware that it will be collected in next gc cycle
     ret.val.gcobj->mark = in_incremental_sweep_stage
-        ? nas_val::gc_status::found
+        ? nas_val::gc_status::alloc_in_sweep_stage
         : nas_val::gc_status::uncollected;
     unused[index].pop_back();
     return ret;

src/nasal_gc.h

@@ -9,6 +9,7 @@
 
 #include <iomanip>
 #include <vector>
+#include <queue>
 #include <chrono>
 #include <thread>
 #include <cstring>
@@ -52,9 +53,9 @@ struct gc {
 
     /* heap increase size */
     u64 incr[GC_TYPE_SIZE] = {
-        256, // vm_str
-        256, // vm_vec
-        256, // vm_hash
+        4,   // vm_str
+        4,   // vm_vec
+        2,   // vm_hash
         256, // vm_func
         256, // vm_upval
         4,   // vm_obj
@@ -62,6 +63,17 @@ struct gc {
         1,   // vm_map
     };
 
+    const u64 max_incr[GC_TYPE_SIZE] = {
+        8192, // vm_str
+        8192, // vm_vec
+        8192, // vm_hash
+        2048, // vm_func
+        2048, // vm_upval
+        256,  // vm_obj
+        256,  // vm_co
+        64,   // vm_map
+    };
+
     // total object count
     u64 total_object_count = 0;
 
@@ -83,16 +95,15 @@ private:
     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>&);
-    void mark_var(std::vector<var>&, var&);
-    void mark_vec(std::vector<var>&, nas_vec&);
-    void mark_hash(std::vector<var>&, nas_hash&);
-    void mark_func(std::vector<var>&, nas_func&);
-    void mark_upval(std::vector<var>&, nas_upval&);
-    void mark_ghost(std::vector<var>&, nas_ghost&);
-    void mark_co(std::vector<var>&, nas_co&);
-    void mark_map(std::vector<var>&, nas_map&);
+    void mark_context_root(std::queue<var>&);
+    void mark_var(std::queue<var>&, var&);
+    void mark_vec(std::queue<var>&, nas_vec&);
+    void mark_hash(std::queue<var>&, nas_hash&);
+    void mark_func(std::queue<var>&, nas_func&);
+    void mark_upval(std::queue<var>&, nas_upval&);
+    void mark_ghost(std::queue<var>&, nas_ghost&);
+    void mark_co(std::queue<var>&, nas_co&);
+    void mark_map(std::queue<var>&, nas_map&);
     void sweep();
 
 public:

src/nasal_type.cpp

@@ -112,10 +112,12 @@ std::ostream& operator<<(std::ostream& out, nas_func& func) {
     }
 
     out << ") {..}";
+    out << " entry: 0x" << std::hex << func.entry << std::dec;
     return out;
 }
 
 void nas_func::clear() {
+    entry = 0;
     dynamic_parameter_index = -1;
     local.clear();
     upval.clear();

src/nasal_type.h

@@ -7,6 +7,7 @@
 #include <sstream>
 #include <iostream>
 #include <vector>
+#include <queue>
 #include <unordered_map>
 
 namespace nasal {
@@ -14,7 +15,6 @@ namespace nasal {
 enum class vm_type: u8 {
     /* none-gc object */
     vm_none = 0, // error type
-    vm_cnt,      // counter for forindex/foreach loop
     vm_addr,     // var* address
     vm_ret,      // return addres(program counter)
     vm_nil,      // nil
@@ -51,9 +51,12 @@ struct nas_map;   // mapper
 // nas_val includes gc-managed types
 struct nas_val {
     enum class gc_status: u8 {
-        uncollected = 0,
-        collected,
-        found
+        uncollected = 0,     // will be collected by sweep
+        collected,           // already collected and put into unused list
+        found,               // marked as referenced
+        alloc_in_sweep_stage // mark it allocated in incremental sweep stage
+                             // still scan in mark stage
+                             // but do not sweep in this gc cycle
     };
 
     gc_status mark;
@@ -80,7 +83,6 @@ public:
     vm_type type = vm_type::vm_none;
     union {
         u64 ret;
-        i64 cnt;
         f64 num;
         var* addr;
         nas_val* gcobj;
@@ -88,7 +90,6 @@ public:
 
 private:
     var(vm_type t, u64 pc) { type = t; val.ret = pc; }
-    var(vm_type t, i64 ct) { type = t; val.cnt = ct; }
     var(vm_type t, f64 n) { type = t; val.num = n; }
     var(vm_type t, var* p) { type = t; val.addr = p; }
     var(vm_type t, nas_val* p) { type = t; val.gcobj = p; }
@@ -114,9 +115,6 @@ public:
     static var ret(u64 pc) {
         return var(vm_type::vm_ret, pc);
     }
-    static var cnt(i64 n) {
-        return var(vm_type::vm_cnt, n);
-    }
     static var num(f64 n) {
         return var(vm_type::vm_num, n);
     }
@@ -131,7 +129,6 @@ public:
     // get value
     var* addr() const { return val.addr; }
     u64 ret() const { return val.ret; }
-    i64& cnt() { return val.cnt; }
     f64 num() const { return val.num; }
 
 public:
@@ -158,7 +155,6 @@ public:
 
 public:
     bool is_none() const { return type == vm_type::vm_none; }
-    bool is_cnt() const { return type == vm_type::vm_cnt; }
     bool is_addr() const { return type == vm_type::vm_addr; }
     bool is_ret() const { return type == vm_type::vm_ret; }
     bool is_nil() const { return type == vm_type::vm_nil; }
@@ -257,20 +253,29 @@ public:
     nas_upval(): on_stack(true), size(0), stack_frame_offset(nullptr) {}
 
     var& operator[](usize n) {
-        return on_stack? stack_frame_offset[n] : elems[n];
+        return on_stack ? stack_frame_offset[n] : elems[n];
     }
 
     void clear() {
         on_stack = true;
         elems.clear();
         size = 0;
+        stack_frame_offset = nullptr;
+    }
+
+    void move_from_stack() {
+        on_stack = false;
+        elems.resize(size);
+        for (u64 i = 0; i < size; ++i) {
+            elems[i] = stack_frame_offset[i];
+        }
     }
 };
 
 struct nas_ghost {
 private:
     using destructor = void (*)(void*);
-    using marker = void (*)(void*, std::vector<var>*);
+    using marker = void (*)(void*, std::queue<var>*);
 
 public:
     std::string type_name;

src/nasal_vm.cpp

@@ -138,7 +138,6 @@ void vm::value_name_form(const var& val) {
         case vm_type::vm_none:  std::clog << "null "; break;
         case vm_type::vm_ret:   std::clog << "ret  "; break;
         case vm_type::vm_addr:  std::clog << "addr "; break;
-        case vm_type::vm_cnt:   std::clog << "cnt  "; break;
         case vm_type::vm_nil:   std::clog << "nil  "; break;
         case vm_type::vm_num:   std::clog << "num  "; break;
         case vm_type::vm_str:   std::clog << "str  "; break;
@@ -161,7 +160,6 @@ void vm::value_info(var& val) {
         case vm_type::vm_none: break;
         case vm_type::vm_ret: return_address_info(val); break;
         case vm_type::vm_addr: memory_address_info(val); break;
-        case vm_type::vm_cnt: std::clog << val.cnt(); break;
         case vm_type::vm_nil: break;
         case vm_type::vm_num: std::clog << val.num(); break;
         case vm_type::vm_str: raw_string_info(val); break;
@@ -509,7 +507,6 @@ std::string vm::report_out_of_range(f64 index, usize real_size) const {
 std::string vm::type_name_string(const var& value) const {
     switch(value.type) {
         case vm_type::vm_none: return "none";
-        case vm_type::vm_cnt: return "counter";
         case vm_type::vm_addr: return "address";
         case vm_type::vm_ret: return "program counter";
         case vm_type::vm_nil: return "nil";

src/nasal_vm.h

@@ -434,9 +434,9 @@ inline void vm::o_newf() {
         func.upval = ctx.funcr.func().upval;
 
         // function created in the same local scope shares same closure
-        var upval = (ctx.upvalr.is_nil())?
-            ngc.alloc(vm_type::vm_upval):
-            ctx.upvalr;
+        var upval = (ctx.upvalr.is_nil())
+            ? ngc.alloc(vm_type::vm_upval)
+            : ctx.upvalr;
         // if no upval scope exists, now it's time to create one
         if (ctx.upvalr.is_nil()) {
             upval.upval().size = ctx.funcr.func().local_size;
@@ -760,25 +760,27 @@ inline void vm::o_cnt() {
         );
         return;
     }
-    (++ctx.top)[0] = var::cnt(-1);
+    (++ctx.top)[0] = var::num(-1.0f);
 }
 
 inline void vm::o_findex() {
-    if ((usize)(++ctx.top[0].cnt())>=ctx.top[-1].vec().size()) {
-        ctx.pc = imm[ctx.pc]-1;
+    ctx.top[0] = var::num(ctx.top[0].num() + 1.0f);
+    if ((usize)ctx.top[0].num() >= ctx.top[-1].vec().size()) {
+        ctx.pc = imm[ctx.pc] - 1;
         return;
     }
-    ctx.top[1] = var::num(ctx.top[0].cnt());
+    ctx.top[1] = ctx.top[0];
     ++ctx.top;
 }
 
 inline void vm::o_feach() {
+    ctx.top[0] = var::num(ctx.top[0].num() + 1.0f);
     auto& ref = ctx.top[-1].vec().elems;
-    if ((usize)(++ctx.top[0].cnt())>=ref.size()) {
+    if ((usize)ctx.top[0].num() >= ref.size()) {
         ctx.pc = imm[ctx.pc]-1;
         return;
     }
-    ctx.top[1] = ref[ctx.top[0].cnt()];
+    ctx.top[1] = ref[ctx.top[0].num()];
     ++ctx.top;
 }
 
@@ -840,7 +842,7 @@ inline void vm::o_callv() {
             return;
         }
     } else {
-        die("must call a vector/hash/string but get " + type_name_string(vec));
+        die("must get element from vector/hash/string, but get " + type_name_string(vec));
         return;
     }
 }
@@ -862,7 +864,7 @@ inline void vm::o_callvi() {
 inline void vm::o_callh() {
     var val = ctx.top[0];
     if (!val.is_hash() && !val.is_map()) {
-        die("must call a hash but get " + type_name_string(val));
+        die("must get element from hash, but get " + type_name_string(val));
         return;
     }
 
@@ -1229,13 +1231,7 @@ inline void vm::o_ret() {
 
     // synchronize upvalue
     if (up.is_upval()) {
-        auto& upval = up.upval();
-        auto size = func.func().local_size;
-        upval.on_stack = false;
-        upval.elems.resize(size);
-        for (u64 i = 0; i < size; ++i) {
-            upval.elems[i] = local[i];
-        }
+        up.upval().move_from_stack();
     }
 
     // cannot use gc.cort to judge,

src/util/gc_stat.cpp

@@ -56,6 +56,20 @@ f64 gc_stat::max_sweep_time_ms() const {
     return (max_sweep_time * 1000.0) / den;
 }
 
+i64 gc_stat::calc_sweep_threshold() {
+    const i64 min_threshold = 4096;
+    if (!total_sweep_count) {
+        return min_threshold;
+    }
+
+    // expect max sweep time = 0.1 ms
+    last_sweep_threshold = static_cast<i64>(0.1f / avg_sweep_time_ms() * last_sweep_threshold);
+    if (last_sweep_threshold < min_threshold) {
+        last_sweep_threshold = min_threshold;
+    }
+    return last_sweep_threshold;
+}
+
 void gc_stat::dump_info() const {
     util::windows_code_page_manager wm;
     wm.set_utf8_output();

src/util/gc_stat.h

@@ -20,6 +20,7 @@ struct gc_stat {
 
     i64 max_mark_time = 0;
     i64 max_sweep_time = 0;
+    i64 last_sweep_threshold = 512;
 
     std::chrono::time_point<std::chrono::high_resolution_clock> start_time;
 
@@ -50,6 +51,7 @@ struct gc_stat {
     f64 avg_sweep_time_ms() const;
     f64 max_mark_time_ms() const;
     f64 max_sweep_time_ms() const;
+    i64 calc_sweep_threshold();
 
     void dump_info() const;
 };

test/gc_test.nas

@@ -1,6 +1,13 @@
 use std.runtime;
 use std.os;
 
+var prev_info = runtime.gc.info();
+var delta = func(prev, curr, member) {
+    var d = int(curr[member] - prev[member]);
+    var t = d < 0 ? "-" : (d == 0 ? "" : "+");
+    return " (" ~ t ~ d ~ ")";
+}
+
 var test_func = func(test_processes...) {
     var test_process_total = maketimestamp();
     test_process_total.stamp();
@@ -17,21 +24,24 @@ var test_func = func(test_processes...) {
     var end_info = runtime.gc.info();
     var gc_total_end = end_info.total;
     var duration = time_stamp.elapsedMSec();
-    println(" ", duration, " ms,\tgc ",
+
+    print(" ", duration, " ms,\tgc ",
         int((gc_total_end-gc_total_begin)*100/duration), "%,\t",
-        int(1000/(duration/size(test_processes))*10)/10, " test(s)/sec"
+        int(1000/(duration/size(test_processes))*10)/10, " test(s)/sec",
+        "\n"
     );
 
     var info = runtime.gc.info();
-    println("+##-gc----------------------");
+    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("| mark count   : ", info.mark_count, delta(prev_info, info, "mark_count"));
+    println("| sweep count  : ", info.sweep_count, delta(prev_info, info, "sweep_count"));
     println("| max mark     : ", info.max_mark, " ms");
     println("| max sweep    : ", info.max_sweep, " ms");
-    println("+---------------------------");
+    println("+----------------------------------------");
+    prev_info = info;
 }
 
 var MAX_ITER_NUM = 0.5e5;
@@ -98,13 +108,29 @@ var append_tree = func {
     var res = [];
     for (var i=0; i<MAX_ITER_NUM; i+=1) {
         append(res, {
-            a: {b: {c:[]}},
+            a: {b: {c:[1, 2, 3, 4]}},
             d: {e: {}},
-            j: {k: {l:{m:[{a:{b:{c:[{}]}}}]}}}
+            j: {k: {l:{m:[{a:{b:{c:[{}, {}]}}}]}}},
+            n: [[], []]
         });
     }
 }
 
+var append_deep_tree = func {
+    var res = {};
+    var tmp = [];
+    for (var i = 0; i < MAX_ITER_NUM; i += 1) {
+        tmp = [[[tmp, tmp]]];
+    }
+    res["vec"] = tmp;
+    tmp = {};
+    for (var i = 0; i < MAX_ITER_NUM; i += 1) {
+        tmp = {a : {a : {a : tmp, b : tmp}}};
+    }
+    res["hash"] = tmp;
+    return res;
+}
+
 for (var i = 0; i < 10; i += 1) {
     test_func(
         append_vec,
@@ -153,6 +179,10 @@ for (var i = 0; i < 10; i += 1) {
 
         append_tree,
         append_tree,
-        append_tree
+        append_tree,
+
+        append_deep_tree,
+        append_deep_tree,
+        append_deep_tree
     );
 }