Test performance regressions

[ngsrinivas]

The ISA refactor may have likely inflated running time significantly for certain critical routines (e.g., interpret, validate)

Will be good to check the new numbers now by running the time tests we already have and comparing the numbers from before and now.

@QiongwenXu could you please check?

[QiongwenXu]

Performance comparison between the commit after today's merge (90478f) and the commit before today's merge (a8b132). I did a temporary removal of printing in running mh_sampler.

The results show that time costs of validator and mh_sampler are similar while time cost of interpret increases a lot, about 5.45 times as before.

Funtion	time cost(after)	time cost(before)
smt prog::gen_smt	203.958 us	194.515 us
validator::set_orig	223.419 us	202.687 us
validator::is_equal_to	18611.1 us	18910.5 us
validator::is_smt_valid	18129.2 us	18354 us
validator::get_orig_output	17243.5 us	17270.9 us
interpret	0.144853 us	0.0265693 us
cost::init	229.902 us	201.476 us
cost::error_cost	18554.1 us	18674.2 us
cost::perf_cost	0.002959 us	0.002556 us
mh_sampler (niter=1000)	4.89057e+06 us	5.16865e+06 us

[ngsrinivas]

Great, thanks for this.

Could you pls profile interpret with gprof or other tools and see where we're spending a lot of time?

Also am I right in understanding that the time for each iteration of mh_sampler has reduced from 5.2 us to 4.9 us? It seems surprising.

[QiongwenXu]

1. profile interpret

Key parts from gprof output

  %   cumulative   self              self     total           
 time   seconds   seconds    calls  Ts/call  Ts/call  name    
  0.00      0.00     0.00   300471     0.00     0.00  std::vector<int, std::allocator<int> >::operator[](unsigned long)
  0.00      0.00     0.00   199988     0.00     0.00  std::vector<inst*, std::allocator<inst*> >::operator[](unsigned long) const
  0.00      0.00     0.00    51078     0.00     0.00  std::vector<int, std::allocator<int> >::size() const
  0.00      0.00     0.00    20000     0.00     0.00  compute_mov(int, int)
  0.00      0.00     0.00    10008     0.00     0.00  std::vector<inst*, std::allocator<inst*> >::size() const
  0.00      0.00     0.00    10000     0.00     0.00  compute_add(int, int, int)
  0.00      0.00     0.00    10000     0.00     0.00  prog_state::clear()
  0.00      0.00     0.00    10000     0.00     0.00  toy_isa_inst::interpret(std::vector<inst*, std::allocator<inst*> > const&, prog_state&, int) const
  0.00      0.00     0.00    10000     0.00     0.00  prog::interpret(prog_state&, int) const

-----------------------------------------------
                0.00    0.00   10000/10000       prog::interpret(prog_state&, int) const [16]
[15]     0.0    0.00    0.00   10000         toy_isa_inst::interpret(std::vector<inst*, std::allocator<inst*> > const&, prog_state&, int) const [15]
                0.00    0.00  259988/300471      std::vector<int, std::allocator<int> >::operator[](unsigned long) [8]
                0.00    0.00  189988/199988      std::vector<inst*, std::allocator<inst*> >::operator[](unsigned long) const [9]
                0.00    0.00   20000/20000       compute_mov(int, int) [11]
                0.00    0.00   10000/10008       std::vector<inst*, std::allocator<inst*> >::size() const [12]
                0.00    0.00   10000/10000       prog_state::clear() [14]
                0.00    0.00   10000/10000       compute_add(int, int, int) [13]
-----------------------------------------------

Seems that functions operator [] of vector<inst*> and vector are called too many times, while in the before version, we do not have vector<inst*> and directly read value from array but not vector.

The following is key code in the after version. The type of ps.regs is vector<int>

#define DSTREG(inst_var) (inst_var)._args[0]
#define DST ps.regs[DSTREG(*instptr_list[insn])]

Maybe replacing vector<inst*> with inst** will improve the performance.

2. Reduction of each iteration of mh_sampler from 5.2 ms to 4.9 ms

I am afraid it cannot be seemed as a reduction. It is within the error range, since the runtime of interpret is a small part in the runtime of mh_sampler.