Skip to content

Commit b63333f

Browse files
oleg-jukovecDifferentialOrange
authored andcommitted
Log potentially long select calls
Potentially long select calls on user spaces tend to be dangerous. A critical log entry containing the current stack traceback is created upon potentially long select calls — a user can explicitly request a full scan though by passing fullscan = true to select's options table argument in which a case a log entry will not be created. Tarantool has a similar implementation[1][2]. 1. tarantool/tarantool#7064 2. tarantool/tarantool#7131 Part of #276
1 parent 68b7820 commit b63333f

File tree

14 files changed

+460
-81
lines changed

14 files changed

+460
-81
lines changed

CHANGELOG.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,10 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
1111

1212
### Changed
1313
* Optimize `crud.select()` without conditions and with `after`.
14+
* Behaviour of potentially long `select` calls: a critical log entry containing
15+
the current stack traceback is created upon such function calls — an user can
16+
explicitly request a full scan through by passing `fullscan=true` to `select`
17+
options table argument in which a case a log entry will not be created (#276).
1418

1519
### Fixed
1620
* `crud.select()` if a condition is '<=' and it's value < `after`.

README.md

Lines changed: 11 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -78,7 +78,7 @@ It can be used to convert received tuples to objects via `crud.unflatten_rows` f
7878
For example:
7979

8080
```lua
81-
res, err = crud.select('customers')
81+
res, err = crud.select('customers', nil, {first = 2})
8282
res
8383
---
8484
- metadata:
@@ -450,6 +450,8 @@ where:
450450
if full primary key equal condition is specified
451451
* `timeout` (`?number`) - `vshard.call` timeout (in seconds)
452452
* `fields` (`?table`) - field names for getting only a subset of fields
453+
* `fullscan` (`?boolean`) - if `true` then a critical log entry will be skipped
454+
on potentially long `select`, see [avoiding full scan](doc/select.md#avoiding-full-scan).
453455
* `mode` (`?string`, `read` or `write`) - if `write` is specified then `select` is
454456
performed on master
455457
* `prefer_replica` (`?boolean`) - if `true` then the preferred target is one of
@@ -472,7 +474,7 @@ Each condition is a table `{operator, field-identifier, value}`:
472474
**Example:**
473475

474476
```lua
475-
crud.select('customers', {{'<=', 'age', 35}})
477+
crud.select('customers', {{'<=', 'age', 35}}, {first = 10})
476478
---
477479
- metadata:
478480
- {'name': 'id', 'type': 'unsigned'}
@@ -496,8 +498,10 @@ See more examples of select queries [here.](https://github.com/tarantool/crud/bl
496498
### Pairs
497499

498500
You can iterate across a distributed space using the `crud.pairs` function.
499-
Its arguments are the same as [`crud.select`](#select) arguments,
500-
but negative `first` values aren't allowed.
501+
Its arguments are the same as [`crud.select`](#select) arguments except
502+
`fullscan` (it does not exist because `crud.pairs` does not generate a critical
503+
log entry on potentially long requests) and negative `first` values aren't
504+
allowed.
501505
User could pass use_tomap flag (false by default) to iterate over flat tuples or objects.
502506

503507
**Example:**
@@ -597,15 +601,15 @@ Returns true or nil with error.
597601
**Example:**
598602

599603
```lua
600-
#crud.select('customers', {{'<=', 'age', 35}})
604+
#crud.select('customers', {{'<=', 'age', 35}}, {first = 10})
601605
---
602606
- 1
603607
...
604608
crud.truncate('customers', {timeout = 2})
605609
---
606610
- true
607611
...
608-
#crud.select('customers', {{'<=', 'age', 35}})
612+
#crud.select('customers', {{'<=', 'age', 35}}, {first = 10})
609613
---
610614
- 0
611615
...
@@ -633,7 +637,7 @@ Returns number or nil with error.
633637
Using `memtx`:
634638

635639
```lua
636-
#crud.select('customers')
640+
#crud.select('customers', nil, {fullscan = true})
637641
---
638642
- 5
639643
...

crud/ratelimit.lua

Lines changed: 125 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,125 @@
1+
-- Mostly it's a copy-paste from tarantool/tarantool log.lua:
2+
-- https://github.com/tarantool/tarantool/blob/29654ffe3638e5a218dd32f1788830ff05c1c05c/src/lua/log.lua
3+
--
4+
-- We have three reasons for the copy-paste:
5+
-- 1. Tarantool has not log.crit() (a function for logging with CRIT level).
6+
-- 2. Only new versions of Tarantool have Ratelimit type.
7+
-- 3. We want own copy of Ratelimit in case the implementation in Tarantool
8+
-- changes. Less pain between Tarantool versions.
9+
local ffi = require('ffi')
10+
11+
local S_CRIT = ffi.C.S_CRIT
12+
local S_WARN = ffi.C.S_WARN
13+
14+
local function say(level, fmt, ...)
15+
if ffi.C.log_level < level then
16+
-- don't waste cycles on debug.getinfo()
17+
return
18+
end
19+
local type_fmt = type(fmt)
20+
local format = "%s"
21+
if select('#', ...) ~= 0 then
22+
local stat
23+
stat, fmt = pcall(string.format, fmt, ...)
24+
if not stat then
25+
error(fmt, 3)
26+
end
27+
elseif type_fmt == 'table' then
28+
-- An implementation in tarantool/tarantool supports encoding a table in
29+
-- JSON, but it requires more dependencies from FFI. So we just deleted
30+
-- it because we don't need such encoding in the module.
31+
error("table not supported", 3)
32+
elseif type_fmt ~= 'string' then
33+
fmt = tostring(fmt)
34+
end
35+
36+
local debug = require('debug')
37+
local frame = debug.getinfo(3, "Sl")
38+
local line, file = 0, 'eval'
39+
if type(frame) == 'table' then
40+
line = frame.currentline or 0
41+
file = frame.short_src or frame.src or 'eval'
42+
end
43+
44+
ffi.C._say(level, file, line, nil, format, fmt)
45+
end
46+
47+
local ratelimit_enabled = true
48+
49+
local function ratelimit_enable()
50+
ratelimit_enabled = true
51+
end
52+
53+
local function ratelimit_disable()
54+
ratelimit_enabled = false
55+
end
56+
57+
local Ratelimit = {
58+
interval = 60,
59+
burst = 10,
60+
emitted = 0,
61+
suppressed = 0,
62+
start = 0,
63+
}
64+
65+
local function ratelimit_new(object)
66+
return Ratelimit:new(object)
67+
end
68+
69+
function Ratelimit:new(object)
70+
object = object or {}
71+
setmetatable(object, self)
72+
self.__index = self
73+
return object
74+
end
75+
76+
function Ratelimit:check()
77+
if not ratelimit_enabled then
78+
return 0, true
79+
end
80+
81+
local clock = require('clock')
82+
local now = clock.monotonic()
83+
local saved_suppressed = 0
84+
if now > self.start + self.interval then
85+
saved_suppressed = self.suppressed
86+
self.suppressed = 0
87+
self.emitted = 0
88+
self.start = now
89+
end
90+
91+
if self.emitted < self.burst then
92+
self.emitted = self.emitted + 1
93+
return saved_suppressed, true
94+
end
95+
self.suppressed = self.suppressed + 1
96+
return saved_suppressed, false
97+
end
98+
99+
function Ratelimit:log_check(lvl)
100+
local suppressed, ok = self:check()
101+
if lvl >= S_WARN and suppressed > 0 then
102+
say(S_WARN, '%d messages suppressed due to rate limiting', suppressed)
103+
end
104+
return ok
105+
end
106+
107+
function Ratelimit:log(lvl, fmt, ...)
108+
if self:log_check(lvl) then
109+
say(lvl, fmt, ...)
110+
end
111+
end
112+
113+
local function log_ratelimited_closure(lvl)
114+
return function(self, fmt, ...)
115+
self:log(lvl, fmt, ...)
116+
end
117+
end
118+
119+
Ratelimit.log_crit = log_ratelimited_closure(S_CRIT)
120+
121+
return {
122+
new = ratelimit_new,
123+
enable = ratelimit_enable,
124+
disable = ratelimit_disable,
125+
}

crud/select/compat/common.lua

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,28 @@
1+
local ratelimit = require('crud.ratelimit')
2+
local check_select_safety_rl = ratelimit.new()
3+
14
local common = {}
25

36
common.SELECT_FUNC_NAME = '_crud.select_on_storage'
47
common.DEFAULT_BATCH_SIZE = 100
58

9+
common.check_select_safety = function(space_name, plan, opts)
10+
if opts.fullscan == true then
11+
return
12+
end
13+
14+
if opts.first ~= nil and math.abs(opts.first) <= 1000 then
15+
return
16+
end
17+
18+
local iter = plan.tarantool_iter
19+
if iter == box.index.EQ or iter == box.index.REQ then
20+
return
21+
end
22+
23+
local rl = check_select_safety_rl
24+
local traceback = debug.traceback()
25+
rl:log_crit("Potentially long select from space '%s'\n %s", space_name, traceback)
26+
end
27+
628
return common

crud/select/compat/select.lua

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -180,6 +180,7 @@ local function build_select_iterator(space_name, user_conditions, opts)
180180
return {
181181
tuples_limit = tuples_limit,
182182
merger = merger,
183+
plan = plan,
183184
space_format = filtered_space_format,
184185
}
185186
end
@@ -252,14 +253,16 @@ local function select_module_call_xc(space_name, user_conditions, opts)
252253
checks('string', '?table', {
253254
after = '?table|cdata',
254255
first = '?number',
255-
timeout = '?number',
256256
batch_size = '?number',
257257
bucket_id = '?number|cdata',
258258
force_map_call = '?boolean',
259259
fields = '?table',
260+
fullscan = '?boolean',
261+
262+
mode = '?vshard_call_mode',
260263
prefer_replica = '?boolean',
261264
balance = '?boolean',
262-
mode = '?vshard_call_mode',
265+
timeout = '?number',
263266
})
264267

265268
opts = opts or {}
@@ -292,6 +295,7 @@ local function select_module_call_xc(space_name, user_conditions, opts)
292295
if err ~= nil then
293296
return nil, err
294297
end
298+
common.check_select_safety(space_name, iter.plan, opts)
295299

296300
local tuples = {}
297301

crud/select/compat/select_old.lua

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -332,6 +332,7 @@ local function select_module_call_xc(space_name, user_conditions, opts)
332332
if err ~= nil then
333333
return nil, err
334334
end
335+
common.check_select_safety(space_name, iter.plan, opts)
335336

336337
local tuples = {}
337338

@@ -366,14 +367,16 @@ function select_module.call(space_name, user_conditions, opts)
366367
checks('string', '?table', {
367368
after = '?table',
368369
first = '?number',
369-
timeout = '?number',
370370
batch_size = '?number',
371371
bucket_id = '?number|cdata',
372372
force_map_call = '?boolean',
373373
fields = '?table',
374+
fullscan = '?boolean',
375+
376+
mode = '?vshard_call_mode',
374377
prefer_replica = '?boolean',
375378
balance = '?boolean',
376-
mode = '?vshard_call_mode',
379+
timeout = '?number',
377380
})
378381

379382
return sharding.wrap_method(select_module_call_xc, space_name, user_conditions, opts)

doc/pairs.md

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,8 @@
11
# Pairs examples
22

33
With ``crud.pairs``, you can iterate across a distributed space.
4-
The arguments are the same as [``crud.select``](https://github.com/tarantool/crud/blob/master/doc/select.md), except of the ``use_tomap`` parameter.
4+
The arguments are the same as [``crud.select``](https://github.com/tarantool/crud/blob/master/doc/select.md) arguments except ``fullscan`` (it does not exist because ``crud.pairs`` does not generate a critical log entry on potentially long requests) and negative ``first`` values aren't allowed.
5+
User could pass ``use_tomap`` flag (false by default) to iterate over flat tuples or objects.
56
Below are examples that may help you.
67
Examples schema is similar to the [select documentation](select.md/#examples-space-format)
78

0 commit comments

Comments
 (0)