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

Author: oleg-jukovec

CHANGELOG.md

@@ -10,6 +10,11 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
 ### Added
 
 ### Changed
+* Behaviour of potentially long `select` calls (`>`, `>=`, `<`, `<=` and
+  `first` > 1000): a critical log entry containing the current stack traceback
+  is created upon such function calls — an 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 (#276).
 
 ### Fixed
 

README.md

@@ -25,7 +25,7 @@ It can be used to convert received tuples to objects via `crud.unflatten_rows` f
 For example:
 
 ```lua
-res, err = crud.select('customers')
+res, err = crud.select('customers', nil, {first = 2})
 res
 ---
 - metadata:
@@ -397,6 +397,8 @@ where:
      if full primary key equal condition is specified
   * `timeout` (`?number`) - `vshard.call` timeout (in seconds)
   * `fields` (`?table`) - field names for getting only a subset of fields
+  * `fullscan` (`?boolean`) - if `true` then a critical log entry will be skipped
+    on potentially long `select` (`>`, `>=`, `<`, `<=` and `first` > 1000)
   * `mode` (`?string`, `read` or `write`) - if `write` is specified then `select` is
     performed on master
   * `prefer_replica` (`?boolean`) - if `true` then the preferred target is one of
@@ -419,7 +421,7 @@ Each condition is a table `{operator, field-identifier, value}`:
 **Example:**
 
 ```lua
-crud.select('customers', {{'<=', 'age', 35}})
+crud.select('customers', {{'<=', 'age', 35}}, {first = 10})
 ---
 - metadata:
   - {'name': 'id', 'type': 'unsigned'}
@@ -443,8 +445,10 @@ See more examples of select queries [here.](https://github.com/tarantool/crud/bl
 ### Pairs
 
 You can iterate across a distributed space using the `crud.pairs` function.
-Its arguments are the same as [`crud.select`](#select) arguments,
-but negative `first` values aren't allowed.
+Its arguments are the same as [`crud.select`](#select) 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.
 User could pass use_tomap flag (false by default) to iterate over flat tuples or objects.
 
 **Example:**
@@ -544,15 +548,15 @@ Returns true or nil with error.
 **Example:**
 
 ```lua
-#crud.select('customers', {{'<=', 'age', 35}})
+#crud.select('customers', {{'<=', 'age', 35}}, {first = 10})
 ---
 - 1
 ...
 crud.truncate('customers', {timeout = 2})
 ---
 - true
 ...
-#crud.select('customers', {{'<=', 'age', 35}})
+#crud.select('customers', {{'<=', 'age', 35}}, {first = 10})
 ---
 - 0
 ...
@@ -580,7 +584,7 @@ Returns number or nil with error.
 Using `memtx`:
 
 ```lua
-#crud.select('customers')
+#crud.select('customers', nil, {fullscan = true})
 ---
 - 5
 ...

crud/ratelimit.lua

@@ -0,0 +1,125 @@
+-- Mostly it's a copy-paste from tarantool/tarantool log.lua:
+-- https://github.com/tarantool/tarantool/blob/29654ffe3638e5a218dd32f1788830ff05c1c05c/src/lua/log.lua
+--
+-- We have three reasons for the copy-paste:
+-- 1. Tarantool has not log.crit() (a function for logging with CRIT level).
+-- 2. Only new versions of Tarantool have Ratelimit type.
+-- 3. We want own copy of Ratelimit in case the implementation in Tarantool
+-- changes. Less pain between Tarantool versions.
+local ffi = require('ffi')
+
+local S_CRIT = ffi.C.S_CRIT
+local S_WARN = ffi.C.S_WARN
+
+local function say(level, fmt, ...)
+    if ffi.C.log_level < level then
+        -- don't waste cycles on debug.getinfo()
+        return
+    end
+    local type_fmt = type(fmt)
+    local format = "%s"
+    if select('#', ...) ~= 0 then
+        local stat
+        stat, fmt = pcall(string.format, fmt, ...)
+        if not stat then
+            error(fmt, 3)
+        end
+    elseif type_fmt == 'table' then
+        -- An implementation in tarantool/tarantool supports encoding a table in
+        -- JSON, but it requires more dependencies from FFI. So we just deleted
+        -- it because we don't need such encoding in the module.
+        error("table not supported", 3)
+    elseif type_fmt ~= 'string' then
+        fmt = tostring(fmt)
+    end
+
+    local debug = require('debug')
+    local frame = debug.getinfo(3, "Sl")
+    local line, file = 0, 'eval'
+    if type(frame) == 'table' then
+        line = frame.currentline or 0
+        file = frame.short_src or frame.src or 'eval'
+    end
+
+    ffi.C._say(level, file, line, nil, format, fmt)
+end
+
+local ratelimit_enabled = true
+
+local function ratelimit_enable()
+    ratelimit_enabled = true
+end
+
+local function ratelimit_disable()
+    ratelimit_enabled = false
+end
+
+local Ratelimit = {
+    interval = 60,
+    burst = 10,
+    emitted = 0,
+    suppressed = 0,
+    start = 0,
+}
+
+local function ratelimit_new(object)
+    return Ratelimit:new(object)
+end
+
+function Ratelimit:new(object)
+    object = object or {}
+    setmetatable(object, self)
+    self.__index = self
+    return object
+end
+
+function Ratelimit:check()
+    if not ratelimit_enabled then
+        return 0, true
+    end
+
+    local clock = require('clock')
+    local now = clock.monotonic()
+    local saved_suppressed = 0
+    if now > self.start + self.interval then
+        saved_suppressed = self.suppressed
+        self.suppressed = 0
+        self.emitted = 0
+        self.start = now
+    end
+
+    if self.emitted < self.burst then
+        self.emitted = self.emitted + 1
+        return saved_suppressed, true
+    end
+    self.suppressed = self.suppressed + 1
+    return saved_suppressed, false
+end
+
+function Ratelimit:log_check(lvl)
+    local suppressed, ok = self:check()
+    if lvl >= S_WARN and suppressed > 0 then
+        say(S_WARN, '%d messages suppressed due to rate limiting', suppressed)
+    end
+    return ok
+end
+
+function Ratelimit:log(lvl, fmt, ...)
+    if self:log_check(lvl) then
+        say(lvl, fmt, ...)
+    end
+end
+
+local function log_ratelimited_closure(lvl)
+    return function(self, fmt, ...)
+        self:log(lvl, fmt, ...)
+    end
+end
+
+Ratelimit.log_crit = log_ratelimited_closure(S_CRIT)
+
+return {
+    new = ratelimit_new,
+    enable = ratelimit_enable,
+    disable = ratelimit_disable,
+}

crud/select/compat/common.lua

@@ -1,6 +1,32 @@
+local ratelimit = require('crud.ratelimit')
+local check_select_safety_rl = ratelimit.new()
+
 local common = {}
 
 common.SELECT_FUNC_NAME = '_crud.select_on_storage'
 common.DEFAULT_BATCH_SIZE = 100
 
+common.check_select_safety = function(space_name, user_conditions, opts)
+    if opts.fullscan ~= nil and opts.fullscan == true then
+        return
+    end
+
+    if opts.first ~= nil and math.abs(opts.first) <= 1000 then
+        return
+    end
+
+    if user_conditions ~= nil then
+        for _, v in ipairs(user_conditions) do
+            local it = v[1]
+            if it ~= nil and type(it) == 'string' and (it == '=' or it == '==') then
+                return
+            end
+        end
+    end
+
+    local rl = check_select_safety_rl
+    local traceback = debug.traceback()
+    rl:log_crit("Potentially long select from space '%s'\n %s", space_name, traceback)
+end
+
 return common

crud/select/compat/select.lua

@@ -252,14 +252,16 @@ local function select_module_call_xc(space_name, user_conditions, opts)
     checks('string', '?table', {
         after = '?table|cdata',
         first = '?number',
-        timeout = '?number',
         batch_size = '?number',
         bucket_id = '?number|cdata',
         force_map_call = '?boolean',
         fields = '?table',
+        fullscan = '?boolean',
+
+        mode = '?vshard_call_mode',
         prefer_replica = '?boolean',
         balance = '?boolean',
-        mode = '?vshard_call_mode',
+        timeout = '?number',
     })
 
     opts = opts or {}
@@ -292,6 +294,7 @@ local function select_module_call_xc(space_name, user_conditions, opts)
     if err ~= nil then
         return nil, err
     end
+    common.check_select_safety(space_name, user_conditions, opts)
 
     local tuples = {}
 

crud/select/compat/select_old.lua

@@ -332,6 +332,7 @@ local function select_module_call_xc(space_name, user_conditions, opts)
     if err ~= nil then
         return nil, err
     end
+    common.check_select_safety(space_name, user_conditions, opts)
 
     local tuples = {}
 
@@ -366,14 +367,16 @@ function select_module.call(space_name, user_conditions, opts)
     checks('string', '?table', {
         after = '?table',
         first = '?number',
-        timeout = '?number',
         batch_size = '?number',
         bucket_id = '?number|cdata',
         force_map_call = '?boolean',
         fields = '?table',
+        fullscan = '?boolean',
+
+        mode = '?vshard_call_mode',
         prefer_replica = '?boolean',
         balance = '?boolean',
-        mode = '?vshard_call_mode',
+        timeout = '?number',
     })
 
     return sharding.wrap_method(select_module_call_xc, space_name, user_conditions, opts)

doc/pairs.md

@@ -1,7 +1,11 @@
 # Pairs examples
 
 With ``crud.pairs``, you can iterate across a distributed space.  
-The arguments are the same as [``crud.select``](https://github.com/tarantool/crud/blob/master/doc/select.md), except of the ``use_tomap`` parameter.  
+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.
+User could pass ``use_tomap`` flag (false by default) to iterate over flat tuples or objects.
 Below are examples that may help you.
 Examples schema is similar to the [select documentation](select.md/#examples-space-format)