Skip to content

Commit bedfdaa

Browse files
TieskeTieske
committed
feat(reuse) added option to recycle timer context
Keeping the timer context alive can cause memory leaks. Hence a new option to set the number of invocations to use a context before recreating the timer in a new context.
1 parent 34b46fe commit bedfdaa

5 files changed

Lines changed: 309 additions & 2 deletions

File tree

‎README.md‎

Lines changed: 35 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,7 @@ http {
3030
shm_name = "timer_shm", -- shm to use for node-wide timers
3131
key_name = "my_key", -- key-name to use for node-wide timers
3232
sub_interval = 0.1, -- max cross worker extra delay
33+
max_use = 1000, -- maximum re-use of timer context
3334
}
3435
3536
local object
@@ -59,7 +60,8 @@ The OpenResty timer is fairly limited, this timer adds a number of common
5960
options as parameters without having to recode (and retest) them in each
6061
project.
6162

62-
* recurring timers (supported by OR as well through `ngx.timer.every`)
63+
* recurring timers (supported by OR as well through `ngx.timer.every`, but this
64+
implementation will not run overlapping timers)
6365

6466
* immediate first run for recurring timers
6567

@@ -77,6 +79,35 @@ project.
7779
See the [online LDoc documentation](https://kong.github.io/lua-resty-timer/topics/README.md.html)
7880
for the complete API.
7981

82+
## Performance and optimizations
83+
84+
This timer implementation is based on "sleeping on a timer-context". This means
85+
that a single timer is created, and in between recurring invocations `ngx.sleep`
86+
is called as a delay to the next invocation. This as opposed to creating a new
87+
Nginx timer for each invocation. This is configurable however.
88+
89+
Creating a new context is a rather expensive operation. Hence we keep the context
90+
alive and just sleep without the need to recreate it. The downside is that there
91+
is the possibility of a memory leak. Since a timer is implemented in OR as a
92+
request and requests are short-lived, some memory is not released until after the
93+
context is destroyed.
94+
95+
The setting `max_use` controls the timer behaviour. The default value is `1000`,
96+
which means that after each `1000` invocations the timer context is destroyed
97+
and a new one is generated (this happens transparent to the user).
98+
99+
Optimizing this setting:
100+
101+
* if the timer interval is more than `60` seconds, then keeping the context
102+
around in idle state for that period is probably more expensive resource wise
103+
than having to recreate the context. So use `max_use == 1` to drop the
104+
context after each invocation.
105+
106+
* if the timer interval is less than `5` seconds then reusing the context makes
107+
sense. Assume recycling to be done once per minute, or for very high
108+
frequency timers (and hence higher risk of memory leak), more than once per
109+
minute.
110+
80111
## History
81112

82113
Versioning is strictly based on [Semantic Versioning](https://semver.org/)
@@ -95,6 +126,9 @@ Versioning is strictly based on [Semantic Versioning](https://semver.org/)
95126
### unreleased
96127

97128
* Feat: provide a stacktrace upon errors in the timer callback
129+
* Feat: add a `max_use` option. This ensures timer-contexts are recycled to
130+
prevent memory leaks.
131+
* Fix: now accounts for execution time of the handler, when rescheduling.
98132

99133
### 1.1.0 (6-Nov-2020)
100134

‎lib/resty/timer.lua‎

Lines changed: 32 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -113,11 +113,30 @@ local function handler(premature, id)
113113
end
114114
end
115115

116-
-- reschedule the timer
116+
-- calculate next interval
117117
local interval = self.sub_interval + self.sub_jitter
118118
local t = now()
119119
next_interval = math.max(0, self.expire + interval - t)
120120
self.expire = t + next_interval
121+
122+
-- do we need to recycle the current timer-context?
123+
local call_count = self.call_count + 1
124+
if call_count > self.max_use then
125+
-- recreate context
126+
local ok, err = timer_at(next_interval, handler, id)
127+
if ok then
128+
self.call_count = 0
129+
return -- exit the while loop, and end this timer context
130+
end
131+
-- couldn't create a timer, so the system seems to be under pressure
132+
-- of timer resources, so we log the error and then fallback on the
133+
-- current context and sleeping. Next invocation will again try and
134+
-- replace the timer context.
135+
if err ~= "process exiting" then
136+
ngx.log(ngx.ERR, LOG_PREFIX, "failed to create timer: " .. err)
137+
end
138+
end
139+
self.call_count = call_count
121140
self = nil -- luacheck: ignore -- just to make sure we're eligible for GC
122141
end
123142

@@ -175,6 +194,9 @@ end
175194
-- this option set, the maximum delay will be `interval + sub_interval`.
176195
-- This option requires the `immediate` and `key_name` options.
177196
--
197+
-- * `max_use` : (optional, number, default 1000) the maximum use count for a
198+
-- timer context before recreating it.
199+
--
178200
-- @function new
179201
-- @param opts table with options
180202
-- @param ... arguments to pass to the callbacks `expire` and `cancel`.
@@ -226,6 +248,7 @@ local function new(opts, ...)
226248
detached = opts.detached, -- should run detached, prevent GC
227249
args = pack(...), -- arguments to pass along
228250
jitter = opts.jitter, -- maximum variance in each schedule
251+
max_use = opts.max_use, -- max use count before recycling timer context
229252
-- callbacks
230253
cb_expire = opts.expire, -- the callback function
231254
cb_cancel = opts.cancel, -- callback function on cancellation
@@ -241,6 +264,7 @@ local function new(opts, ...)
241264
premature_reason = nil, -- inicator why we're being cancelled
242265
gc_proxy = nil, -- userdata proxy to track GC
243266
expire = nil, -- time when timer expires
267+
call_count = 0, -- call_count in current timer context
244268
}
245269

246270
assert(self.interval, "expected 'interval' to be a number")
@@ -279,6 +303,13 @@ local function new(opts, ...)
279303
self.jitter = 0
280304
self.sub_jitter = 0
281305
end
306+
if self.max_use then
307+
assert(self.recurring, "'max_use' can only be specified on recurring timers")
308+
assert(type(self.max_use) == "number", "expected 'max_use' to be a number")
309+
assert(self.max_use > 0, "expected 'max_use' to be greater than 0")
310+
else
311+
self.max_use = 1000
312+
end
282313
if self.key_name then
283314
assert(type(self.key_name) == "string", "expected 'key_name' to be a string")
284315
assert(opts.shm_name, "'shm_name' is required when specifying 'key_name'")

‎t/00-new.t‎

Lines changed: 66 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -681,3 +681,69 @@ GET /t
681681

682682
--- error_log
683683
expected 'jitter' to be greater than or equal to 0
684+
685+
686+
687+
=== TEST 19: new() max_use must be a number
688+
--- http_config eval: $::HttpConfig
689+
--- config
690+
location = /t {
691+
content_by_lua_block {
692+
local timer = require("resty.timer")
693+
local options = {
694+
interval = 1,
695+
max_use = "hello",
696+
recurring = true,
697+
immediate = false,
698+
detached = false,
699+
expire = function(arg1, arg2, arg3)
700+
ngx.log(ngx.ERR, "EXPIRE ", arg1, arg2, arg3)
701+
end,
702+
}
703+
local ok, err = pcall(timer.new, options, "arg1", nil, "arg3")
704+
if ok then
705+
ngx.say(true)
706+
else
707+
ngx.log(ngx.ERR, err)
708+
end
709+
}
710+
}
711+
--- request
712+
GET /t
713+
--- response_body
714+
715+
--- error_log
716+
expected 'max_use' to be a number
717+
718+
719+
720+
=== TEST 20: new() max_use must be > 0
721+
--- http_config eval: $::HttpConfig
722+
--- config
723+
location = /t {
724+
content_by_lua_block {
725+
local timer = require("resty.timer")
726+
local options = {
727+
interval = 1,
728+
max_use = 0,
729+
recurring = true,
730+
immediate = false,
731+
detached = false,
732+
expire = function(arg1, arg2, arg3)
733+
ngx.log(ngx.ERR, "EXPIRE ", arg1, arg2, arg3)
734+
end,
735+
}
736+
local ok, err = pcall(timer.new, options, "arg1", nil, "arg3")
737+
if ok then
738+
ngx.say(true)
739+
else
740+
ngx.log(ngx.ERR, err)
741+
end
742+
}
743+
}
744+
--- request
745+
GET /t
746+
--- response_body
747+
748+
--- error_log
749+
expected 'max_use' to be greater than 0

‎t/02-timer-reuse-1.t‎

Lines changed: 176 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,176 @@
1+
use Test::Nginx::Socket::Lua;
2+
use Cwd qw(cwd);
3+
4+
workers(1);
5+
6+
plan tests => repeat_each() * (blocks() * 2) + 1;
7+
8+
my $pwd = cwd();
9+
10+
our $HttpConfig = qq{
11+
lua_package_path "$pwd/lib/?.lua;;";
12+
lua_shared_dict test_shm 8m;
13+
lua_shared_dict timer_shm 8m;
14+
};
15+
16+
run_tests();
17+
18+
__DATA__
19+
20+
=== TEST 1: new() timer runs periodically
21+
--- http_config eval: $::HttpConfig
22+
--- config
23+
location = /t {
24+
content_by_lua_block {
25+
local timer = require("resty.timer")
26+
local options = {
27+
interval = 0.1,
28+
recurring = true,
29+
immediate = false,
30+
detached = false,
31+
max_reuse = 1,
32+
expire = function(arg1, arg2, arg3)
33+
ngx.log(ngx.ERR, "EXPIRE ", arg1, arg2, arg3)
34+
end,
35+
cancel = function(reason, arg1, arg2, arg3)
36+
ngx.log(ngx.ERR, "CANCEL ", reason, arg1, arg2, arg3)
37+
end,
38+
--shm_name = "timer_shm",
39+
--key_name = "my_key",
40+
}
41+
local t = timer(options, "arg1", nil, "arg3")
42+
ngx.sleep(0.59) -- 5 occurences
43+
t:cancel()
44+
ngx.say(true)
45+
}
46+
}
47+
--- request
48+
GET /t
49+
--- response_body
50+
true
51+
--- grep_error_log eval: qr/EXPIRE arg1nilarg3|CANCEL USERarg1nilarg3/
52+
--- grep_error_log_out eval
53+
qr/^EXPIRE arg1nilarg3
54+
EXPIRE arg1nilarg3
55+
EXPIRE arg1nilarg3
56+
EXPIRE arg1nilarg3
57+
EXPIRE arg1nilarg3
58+
CANCEL USERarg1nilarg3$/
59+
60+
61+
62+
=== TEST 2: new() only a single timer runs per shm key
63+
--- http_config eval: $::HttpConfig
64+
--- config
65+
location = /t {
66+
content_by_lua_block {
67+
local timer = require("resty.timer")
68+
local count = 0
69+
local options = {
70+
interval = 0.1,
71+
sub_interval = 0.001,
72+
recurring = true,
73+
immediate = true,
74+
detached = false,
75+
max_reuse = 1,
76+
expire = function(arg1, arg2, arg3)
77+
count = count + 1
78+
end,
79+
shm_name = "timer_shm",
80+
key_name = "my_key",
81+
}
82+
for x = 1,10 do
83+
-- create 10 timers with same shm key
84+
-- only 1 should run
85+
timer(options, "arg1", nil, "arg3")
86+
end
87+
-- sleep 5 times interval => + "immediate" = 6 executions
88+
ngx.sleep(0.55) -- could be 10 x 6 = 60 occurences
89+
ngx.say(count)
90+
}
91+
}
92+
--- request
93+
GET /t
94+
--- response_body
95+
6
96+
97+
98+
99+
=== TEST 3: new() timer runs immediately
100+
--- http_config eval: $::HttpConfig
101+
--- config
102+
location = /t {
103+
content_by_lua_block {
104+
local timer = require("resty.timer")
105+
local count = 0
106+
local options = {
107+
interval = 0.1,
108+
recurring = true,
109+
immediate = true,
110+
detached = false,
111+
max_reuse = 1,
112+
expire = function(arg1, arg2, arg3)
113+
count = count + 1
114+
end,
115+
--shm_name = "timer_shm",
116+
--key_name = "my_key",
117+
}
118+
local t = timer(options, "arg1", nil, "arg3")
119+
ngx.sleep(0.15) -- could be 1 occurence, +1 for immediate
120+
ngx.say(count)
121+
}
122+
}
123+
--- request
124+
GET /t
125+
--- response_body
126+
2
127+
128+
129+
130+
=== TEST 4: new() sub_interval is honored
131+
--- http_config eval: $::HttpConfig
132+
--- config
133+
location = /t {
134+
content_by_lua_block {
135+
local timer = require("resty.timer")
136+
local count = 0
137+
local t = {}
138+
ngx.update_time()
139+
local t0 = ngx.now()
140+
local options = {
141+
interval = 0.1,
142+
recurring = true,
143+
immediate = true,
144+
detached = false,
145+
max_reuse = 1,
146+
expire = function(t_id)
147+
count = count + 1
148+
ngx.update_time()
149+
--print("========EXEC=======> ", t_id, " @ ", 1000*(ngx.now() - t0))
150+
if t_id == 1 then
151+
t[t_id]:cancel() -- cancel so it ran only once
152+
end
153+
end,
154+
shm_name = "timer_shm",
155+
key_name = "my_key",
156+
sub_interval = 0.01,
157+
}
158+
for x = 1,2 do
159+
-- create 2 timers with same shm key
160+
-- only 1 should run
161+
t[x] = timer(options, x)
162+
ngx.update_time()
163+
--print("=======SCHED=======> ",x, " @ ", 1000*(ngx.now() - t0))
164+
-- wait till half way interval before scheduling the second one
165+
ngx.sleep(options.interval / 2)
166+
end
167+
-- first timer ran on start, so count == 1, timer 1 was immediately cancelled
168+
ngx.sleep(options.interval / 2) -- lock set by 1st timer expires, the first half was already done when creating the timers above
169+
ngx.sleep(options.sub_interval * 1.5) -- by now the second timer should have taken over (count == 2)
170+
ngx.say(count) --> 2; first when first timer starts, 2nd by second timer after it picked up
171+
}
172+
}
173+
--- request
174+
GET /t
175+
--- response_body
176+
2

t/02-garbagecollect.t renamed to t/03-garbagecollect.t

File renamed without changes.

0 commit comments

Comments
 (0)