Skip to content

Commit f6b9424

Browse files
committed
Log potentially long count calls
Potentially long count calls on user spaces tend to be dangerous. A critical log entry containing the current stack traceback is created upon potentially long count calls — a user can explicitly request a full scan though by passing fullscan = true to count's options table argument in which a case a log entry will not be created. Closes #276
1 parent 62ee51a commit f6b9424

File tree

7 files changed

+141
-30
lines changed

7 files changed

+141
-30
lines changed

CHANGELOG.md

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

1212
### Changed
13-
* Behaviour of potentially long `select` calls (`>`, `>=`, `<`, `<=` and
14-
`first` > 1000): a critical log entry containing the current stack traceback
15-
is created upon such function calls — an user can explicitly request a full
16-
scan though by passing fullscan=true to select's options table argument in
17-
which a case a log entry will not be created (#276).
13+
* Behaviour of potentially long `select` and `count` calls (`>`, `>=`, `<`, `<=`
14+
and `first` > 1000): a critical log entry containing the current stack
15+
traceback is created upon such function calls — an user can explicitly request
16+
a full scan though by passing fullscan=true to select's options table argument
17+
in which a case a log entry will not be created (#276).
1818

1919
### Fixed
2020

README.md

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -637,6 +637,8 @@ where:
637637
* `force_map_call` (`?boolean`) - if `true`
638638
then the map call is performed without any optimizations even,
639639
default value is `false`
640+
* `fullscan` (`?boolean`) - if `true` then a critical log entry will be skipped
641+
on potentially long `count` (`>`, `>=`, `<`, `<=`)
640642
* `mode` (`?string`, `read` or `write`) - if `write` is specified then `count` is
641643
performed on master, default value is `read`
642644
* `prefer_replica` (`?boolean`) - if `true` then the preferred target is one of
@@ -646,9 +648,9 @@ where:
646648
default value is `false`
647649

648650
```lua
649-
crud.count('customers', {{'<=', 'age', 35}})
651+
crud.count('customers', {{'==', 'age', 35}})
650652
---
651-
- 5
653+
- 1
652654
...
653655
```
654656

crud/count.lua

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ local sharding = require('crud.common.sharding')
1010
local filters = require('crud.compare.filters')
1111
local count_plan = require('crud.compare.plan')
1212
local dev_checks = require('crud.common.dev_checks')
13+
local ratelimit = require('crud.ratelimit')
1314
local schema = require('crud.common.schema')
1415
local sharding_metadata_module = require('crud.common.sharding.sharding_metadata')
1516

@@ -90,6 +91,26 @@ function count.init()
9091
_G._crud.count_on_storage = count_on_storage
9192
end
9293

94+
local check_count_safety_rl = ratelimit.new()
95+
local function check_count_safety(space_name, user_conditions, opts)
96+
if opts.fullscan ~= nil and opts.fullscan == true then
97+
return
98+
end
99+
100+
if user_conditions ~= nil then
101+
for _, v in ipairs(user_conditions) do
102+
local it = v[1]
103+
if it ~= nil and type(it) == 'string' and (it == '=' or it == '==') then
104+
return
105+
end
106+
end
107+
end
108+
109+
local rl = check_count_safety_rl
110+
local traceback = debug.traceback()
111+
rl:log_crit("Potentially long count from space '%s'\n %s", space_name, traceback)
112+
end
113+
93114
-- returns result, err, need_reload
94115
-- need_reload indicates if reloading schema could help
95116
-- see crud.common.schema.wrap_func_reload()
@@ -98,6 +119,7 @@ local function call_count_on_router(space_name, user_conditions, opts)
98119
timeout = '?number',
99120
bucket_id = '?number|cdata',
100121
force_map_call = '?boolean',
122+
fullscan = '?boolean',
101123
yield_every = '?number',
102124
prefer_replica = '?boolean',
103125
balance = '?boolean',
@@ -148,6 +170,8 @@ local function call_count_on_router(space_name, user_conditions, opts)
148170
return nil, CountError:new("Failed to plan count: %s", err), const.NEED_SCHEMA_RELOAD
149171
end
150172

173+
check_count_safety(space_name, user_conditions, opts)
174+
151175
-- set replicasets to count from
152176
local replicasets_to_count = replicasets
153177

@@ -297,6 +321,7 @@ function count.call(space_name, user_conditions, opts)
297321
timeout = '?number',
298322
bucket_id = '?number|cdata',
299323
force_map_call = '?boolean',
324+
fullscan = '?boolean',
300325
yield_every = '?number',
301326
prefer_replica = '?boolean',
302327
balance = '?boolean',

test/helper.lua

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -488,4 +488,17 @@ function helpers.count_on_replace_triggers(server, space_name)
488488
]], {space_name})
489489
end
490490

491+
function helpers.fflush_cluster_stdout(cluster, capture)
492+
-- Sometimes we have a delay here. This hack helps to wait for the end of
493+
-- the output. It shouldn't take much time.
494+
cluster:server('router').net_box:eval([[
495+
require('log').error("crud fflush stdout message")
496+
]])
497+
local captured = ""
498+
while not string.find(captured, "crud fflush stdout message", 1, true) do
499+
captured = captured .. (capture:flush().stdout or "")
500+
end
501+
return captured
502+
end
503+
491504
return helpers

test/integration/count_test.lua

Lines changed: 91 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ local fio = require('fio')
22
local clock = require('clock')
33

44
local t = require('luatest')
5+
local luatest_capture = require('luatest.capture')
56

67
local helpers = require('test.helper')
78

@@ -26,6 +27,9 @@ pgroup.before_all(function(g)
2627
g.cluster:server('router').net_box:eval([[
2728
require('crud').cfg{ stats = true }
2829
]])
30+
g.cluster:server('router').net_box:eval([[
31+
require('crud.ratelimit').disable()
32+
]])
2933
end)
3034

3135
pgroup.after_all(function(g) helpers.stop_cluster(g.cluster) end)
@@ -37,14 +41,14 @@ pgroup.before_each(function(g)
3741
end)
3842

3943
pgroup.test_count_non_existent_space = function(g)
40-
local result, err = g.cluster.main_server.net_box:call('crud.count', {'non_existent_space'})
44+
local result, err = g.cluster.main_server.net_box:call('crud.count', {'non_existent_space', nil, {fullscan = true}})
4145

4246
t.assert_equals(result, nil)
4347
t.assert_str_contains(err.err, "Space \"non_existent_space\" doesn't exist")
4448
end
4549

4650
pgroup.test_count_empty_space = function(g)
47-
local result, err = g.cluster.main_server.net_box:call('crud.count', {'customers'})
51+
local result, err = g.cluster.main_server.net_box:call('crud.count', {'customers', nil, {fullscan = true}})
4852

4953
t.assert_equals(err, nil)
5054
t.assert_equals(result, 0)
@@ -69,7 +73,7 @@ pgroup.test_not_valid_operation = function(g)
6973
}
7074

7175
local result, err = g.cluster.main_server.net_box:call('crud.count',
72-
{'customers', conditions}
76+
{'customers', conditions, {fullscan = true}}
7377
)
7478

7579
t.assert_equals(result, nil)
@@ -89,6 +93,79 @@ pgroup.test_conditions_with_non_existed_field = function(g)
8993
t.assert_equals(result, 0)
9094
end
9195

96+
97+
local count_safety_cases = {
98+
nil_and_nil_opts = {
99+
has_crit = true,
100+
user_conditions = nil,
101+
opts = nil,
102+
},
103+
fullscan_false = {
104+
has_crit = true,
105+
user_conditions = nil,
106+
opts = {fullscan = false},
107+
},
108+
fullscan_true = {
109+
has_crit = false,
110+
user_conditions = nil,
111+
opts = {fullscan = true},
112+
},
113+
non_equal_conditions = {
114+
has_crit = true,
115+
user_conditions = {
116+
{'>=', 'last_name', 'A'},
117+
{'<=', 'last_name', 'Z'},
118+
{'>', 'city', 'A'},
119+
{'<', 'city', 'Z'},
120+
},
121+
opts = nil,
122+
},
123+
equal_condition = {
124+
has_crit = false,
125+
user_conditions = {
126+
{'>=', 'last_name', 'A'},
127+
{'<=', 'last_name', 'Z'},
128+
{'=', 'city', 'A'},
129+
},
130+
opts = nil,
131+
},
132+
equal_condition2 = {
133+
has_crit = false,
134+
user_conditions = {
135+
{'>=', 'last_name', 'A'},
136+
{'<=', 'last_name', 'Z'},
137+
{'==', 'city', 'A'},
138+
},
139+
opts = nil,
140+
},
141+
}
142+
143+
for name, case in pairs(count_safety_cases) do
144+
local space = 'customers'
145+
local crit_log = "C> Potentially long count from space '" .. space .. "'"
146+
local test_name = ('test_count_safety_%s'):format(name)
147+
148+
pgroup[test_name] = function(g)
149+
local uc = case.user_conditions
150+
local opts = case.opts
151+
local capture = luatest_capture:new()
152+
capture:enable()
153+
154+
local _, err = g.cluster.main_server.net_box:call('crud.count', {space, uc, opts})
155+
t.assert_equals(err, nil)
156+
157+
local captured = helpers.fflush_cluster_stdout(g.cluster, capture)
158+
159+
if case.has_crit then
160+
t.assert_str_contains(captured, crit_log)
161+
else
162+
t.assert_equals(string.find(captured, crit_log, 1, true), nil)
163+
end
164+
165+
capture:disable()
166+
end
167+
end
168+
92169
pgroup.test_count_all = function(g)
93170
-- let's insert five tuples on different replicasets
94171
-- (two tuples on one replica and three on the other)
@@ -118,7 +195,7 @@ pgroup.test_count_all = function(g)
118195
})
119196

120197
local result, err = g.cluster.main_server.net_box:call('crud.count',
121-
{'customers'}
198+
{'customers', nil, {fullscan = true}}
122199
)
123200

124201
t.assert_equals(err, nil)
@@ -154,7 +231,7 @@ pgroup.test_count_all_with_yield_every = function(g)
154231
})
155232

156233
local result, err = g.cluster.main_server.net_box:call('crud.count',
157-
{'customers', nil, {yield_every = 1}}
234+
{'customers', nil, {yield_every = 1, fullscan = true}}
158235
)
159236

160237
t.assert_equals(err, nil)
@@ -190,7 +267,7 @@ pgroup.test_count_all_with_yield_every_0 = function(g)
190267
})
191268

192269
local result, err = g.cluster.main_server.net_box:call('crud.count',
193-
{'customers', nil, {yield_every = 0}}
270+
{'customers', nil, {yield_every = 0, fullscan = true}}
194271
)
195272

196273
t.assert_equals(result, nil)
@@ -312,7 +389,7 @@ pgroup.test_ge_condition_with_index = function(g)
312389
local expected_len = 3
313390

314391
local result, err = g.cluster.main_server.net_box:call('crud.count',
315-
{'customers', conditions}
392+
{'customers', conditions, {fullscan = true}}
316393
)
317394

318395
t.assert_equals(err, nil)
@@ -354,7 +431,7 @@ pgroup.test_gt_condition_with_index = function(g)
354431
local expected_len = 1
355432

356433
local result, err = g.cluster.main_server.net_box:call('crud.count',
357-
{'customers', conditions}
434+
{'customers', conditions, {fullscan = true}}
358435
)
359436

360437
t.assert_equals(err, nil)
@@ -396,7 +473,7 @@ pgroup.test_le_condition_with_index = function(g)
396473
local expected_len = 4
397474

398475
local result, err = g.cluster.main_server.net_box:call('crud.count',
399-
{'customers', conditions}
476+
{'customers', conditions, {fullscan = true}}
400477
)
401478

402479
t.assert_equals(err, nil)
@@ -438,7 +515,7 @@ pgroup.test_lt_condition_with_index = function(g)
438515
local expected_len = 2
439516

440517
local result, err = g.cluster.main_server.net_box:call('crud.count',
441-
{'customers', conditions}
518+
{'customers', conditions, {fullscan = true}}
442519
)
443520

444521
t.assert_equals(err, nil)
@@ -543,6 +620,7 @@ pgroup.test_opts_not_damaged = function(g)
543620
mode = 'read',
544621
prefer_replica = false,
545622
balance = false,
623+
fullscan = true
546624
}
547625
local new_count_opts, err = g.cluster.main_server:eval([[
548626
local crud = require('crud')
@@ -586,7 +664,7 @@ pgroup.test_count_no_map_reduce = function(g)
586664
local result, err = g.cluster.main_server.net_box:call('crud.count', {
587665
'customers',
588666
nil,
589-
{bucket_id = 2804, timeout = 1},
667+
{bucket_id = 2804, timeout = 1, fullscan = true},
590668
})
591669
t.assert_equals(err, nil)
592670
t.assert_equals(result, 1)
@@ -647,7 +725,7 @@ pgroup.test_count_timeout = function(g)
647725
local begin = clock.proc()
648726

649727
local result, err = g.cluster.main_server.net_box:call('crud.count',
650-
{'customers', conditions, {timeout = timeout}}
728+
{'customers', conditions, {timeout = timeout, fullscan = true}}
651729
)
652730

653731
t.assert_equals(err, nil)
@@ -688,7 +766,7 @@ pgroup.test_composite_index = function(g)
688766
}
689767

690768
-- no after
691-
local result, err = g.cluster.main_server.net_box:call('crud.count', {'customers', conditions})
769+
local result, err = g.cluster.main_server.net_box:call('crud.count', {'customers', conditions}, {fullscan = true})
692770

693771
t.assert_equals(err, nil)
694772
t.assert_equals(result, 4)

test/integration/read_calls_strategies_test.lua

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -111,7 +111,8 @@ pgroup.test_count = function(g)
111111
local _, err = g.cluster.main_server.net_box:call('crud.count', {'customers', nil, {
112112
mode = g.params.mode,
113113
balance = g.params.balance,
114-
prefer_replica = g.params.prefer_replica
114+
prefer_replica = g.params.prefer_replica,
115+
fullscan = true
115116
}})
116117
t.assert_equals(err, nil)
117118
local vshard_calls = g.get_vshard_calls('call_impl')

test/integration/select_test.lua

Lines changed: 1 addition & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -174,15 +174,7 @@ for name, case in pairs(select_safety_cases) do
174174
local _, err = g.cluster.main_server.net_box:call('crud.select', {space, uc, opts})
175175
t.assert_equals(err, nil)
176176

177-
-- We have a delay here. This hack helps to wait for the end of the output.
178-
-- It shouldn't take much time.
179-
g.cluster:server('router').net_box:eval([[
180-
require('log').error("end of test_select_nil case")
181-
]])
182-
local captured = ""
183-
while not string.find(captured, "end of test_select_nil case", 1, true) do
184-
captured = captured .. (capture:flush().stdout or "")
185-
end
177+
local captured = helpers.fflush_cluster_stdout(g.cluster, capture)
186178

187179
if case.has_crit then
188180
t.assert_str_contains(captured, crit_log)

0 commit comments

Comments
 (0)