Timing Lua Code Correctly in OpenResty
This tutorial demonstrates both the right ways and wrong ways of benchmarking user Lua code in OpenResty.
cd ~
mkdir time-lua
cd time-lua/
First of all, make sure our CPU is always at its full speed.
echo performance | sudo tee /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor
It usually takes the value powersave
by default and we need to set it to performance
instead.
The simplest way to time some Lua code is to use the time
command with the resty
command.
time resty -e 'ngx.re.find("hello, world.", [[\w+\.]], "jo")'
But there is a catch. The resty
command itself has a startup and exiting overhead.
time resty -e ''
We can see there’s overhead of about 11 milliseconds on this machine.
Instead, we should use the ngx.now
Lua API function provided by OpenResty.
restydoc -s ngx.now
Let’s put our Lua code into a file named ./bench.lua
for better readablility.
We make the following edits:
- First of all, we make sure the cached time inside nginx is up to date.
- And then we record the begin time which has millisecond precision.
- And then put our aforementioned regex matching call.
- And then we update our cached time again.
- Finally, output the elapsed time by doing a time subtraction.
- Let’s save the file.
ngx.update_time()
local begin = ngx.now()
ngx.re.find("hello, world.", [[\w+\.]], "jo")
ngx.update_time()
ngx.say("elapsed seconds: ", ngx.now() - begin)
Then run the resty
shell command.
resty bench.lua
It records about a latency of about 1 millisecond. But we will soon see it is very inaccurate.
The correct way is to make the following edits in the bench.lua
file:
- Put the call into a Lua function named
target
. - And then call this function first for 100 times as a warmup. Now this
target
function should be JIT compiled after this loop is executed. - And then inside the timed code region, we call it repeatedly for 10 million times.
- Finally we compute the average time.
local function target()
ngx.re.find("hello, world.", [[\w+\.]], "jo")
end
for i = 1, 100 do
target()
end
ngx.update_time()
local begin = ngx.now()
local N = 1e7
for i = 1, N do
target()
end
ngx.update_time()
ngx.say("elapsed: ", (ngx.now() - begin) / N)
We now run this script again.
resty bench.lua
We can see that it is merely about 30 nanoseconds per call. So many many times faster than the previous result!
Actualy we can further make sure no dead GC objects hanging around before we time the code. Just insert the following line of code before the first ngx.update_time()
call.
collectgarbage()
Here we force a full GC cycle before recording the begin time.
It does not help much with our example here, however. This is because our timed code does not create many GC objects anyway.
We can make the target
function faster by avoiding unnecessary Lua table lookup operations.
local re_find = ngx.re.find
local function target()
re_find("hello, world.", [[\w+\.]], "jo")
end
But the difference may not be measurable here.
This is what I’d cover today. Hopefully you find it interesting.
If you like this tutorial, please subscribe to this blog site and our YouTube channel. Thank you!
About The Author
Yichun Zhang (Github handle: agentzh), is the original creator of the OpenResty® open-source project and the CEO of OpenResty Inc..
Yichun is one of the earliest advocates and leaders of “open-source technology”. He worked at many internationally renowned tech companies, such as Cloudflare, Yahoo!. He is a pioneer of “edge computing”, “dynamic tracing” and “machine coding”, with over 22 years of programming and 16 years of open source experience. Yichun is well-known in the open-source space as the project leader of OpenResty®, adopted by more than 40 million global website domains.
OpenResty Inc., the enterprise software start-up founded by Yichun in 2017, has customers from some of the biggest companies in the world. Its flagship product, OpenResty XRay, is a non-invasive profiling and troubleshooting tool that significantly enhances and utilizes dynamic tracing technology. And its OpenResty Edge product is a powerful distributed traffic management and private CDN software product.
As an avid open-source contributor, Yichun has contributed more than a million lines of code to numerous open-source projects, including Linux kernel, Nginx, LuaJIT, GDB, SystemTap, LLVM, Perl, etc. He has also authored more than 60 open-source software libraries.