Slowness due to memory allocation related problems

  • From: Aapo Talvensaari <aapo.talvensaari@xxxxxxxxx>
  • To: luajit@xxxxxxxxxxxxx
  • Date: Tue, 26 Apr 2016 15:20:56 +0300

Hi,

I have been thinking this a few months. I'm talking about this:
https://github.com/bungle/lua-resty-template#benchmarks

(to install and test, just download resty dir from here:
https://github.com/bungle/lua-resty-template/tree/master/lib + its content
and subdirs of course)

With latest version of lua-resty-template, and when I do run that test
shown in above benchmars link with the default 1000 iterations, I do get
these results:

Code:

local benchmark = require "resty.template.microbenchmark"
benchmark.run(1000)

Results LuaJIT 2.1.0beta1:

Running 1000 iterations in each test
Parsing Time: 0.004565
Compilation Time: 0.032759 (template)
Compilation Time: 0.000113 (template, cached)
Execution Time: 0.034629 (same template)
Execution Time: 0.003920 (same template, cached)
Execution Time: 0.067805 (different template)
Execution Time: 0.010809 (different template, cached)
Execution Time: 0.058226 (different template, different context)
Execution Time: 0.010414 (different template, different context, cached)
Total Time: 0.223240

Results PUC-Lua 5.1:

Running 1000 iterations in each test
Parsing Time: 0.013813
Compilation Time: 0.056981 (template)
Compilation Time: 0.000334 (template, cached)
Execution Time: 0.075922 (same template)
Execution Time: 0.008075 (same template, cached)
Execution Time: 0.085693 (different template)
Execution Time: 0.014121 (different template, cached)
Execution Time: 0.083733 (different template, different context)
Execution Time: 0.014070 (different template, different context, cached)
Total Time: 0.352742

Everything as expected, LuaJIT is a whole lot faster than Lua. But so far
so good, let's change iteration count to 10000, and let's try again.

Code:

local benchmark = require "resty.template.microbenchmark"
benchmark.run(10000)

Results LuaJIT 2.1.0beta1:

Running 10000 iterations in each test
Parsing Time: 0.042928
Compilation Time: 0.243929 (template)
Compilation Time: 0.000122 (template, cached)
Execution Time: 0.351872 (same template)
Execution Time: 0.030897 (same template, cached)
Execution Time: 5.375298 (different template)
Execution Time: 1.256949 (different template, cached)
Execution Time: 5.395208 (different template, different context)
Execution Time: 1.292129 (different template, different context, cached)
Total Time: 13.989332

Results PUC-Lua 5.1:

Running 10000 iterations in each test
Parsing Time: 0.138049
Compilation Time: 0.562498 (template)
Compilation Time: 0.003265 (template, cached)
Execution Time: 0.672406 (same template)
Execution Time: 0.088390 (same template, cached)
Execution Time: 1.110815 (different template)
Execution Time: 0.157976 (different template, cached)
Execution Time: 1.107282 (different template, different context)
Execution Time: 0.145329 (different template, different context, cached)
Total Time: 3.986010

Now, as you can see PUC-Lua results grow linearly. 10 x more rounds equals
about ~10 x more time. But with LuaJIT there seems to be a totally
different story. 10 x more rounds with LuaJIT yields to something like 65 x
more time spend on benchmark. Now I suspect this has to do with this TRACE:

[TRACE --- 0x013a78c8:8 -- failed to allocate mcode memory at 0x013a78c8:11]

It seems that whenever this happens (on this test it happened two times),
there is going to be a huge hit on performance on LuaJIT. Is this something
that is expected. PUC-Lua seems to handle this linearly even with larger
iteration counts.

I know the test is a toy test, and it may not have anything important in a
real world scenarios. I just want to know if there is a regression or
something in LuaJIT that causes this huge a hit in benchmarks. This code
may be used to reproduce this behavior.


Regards
Aapo

Other related posts: